1/* 2 * Part of Very Secure FTPd 3 * Licence: GPL v2 4 * Author: Chris Evans 5 * 6 * logging.c 7 */ 8 9#include "logging.h" 10#include "tunables.h" 11#include "utility.h" 12#include "str.h" 13#include "sysutil.h" 14#include "sysstr.h" 15#include "session.h" 16 17/* File local functions */ 18static int vsf_log_type_is_transfer(enum EVSFLogEntryType type); 19static void vsf_log_common(struct vsf_session* p_sess, int succeeded, 20 enum EVSFLogEntryType what, 21 const struct mystr* p_str); 22static void vsf_log_do_log_vsftpd_format(struct vsf_session* p_sess, 23 struct mystr* p_str, int succeeded, 24 enum EVSFLogEntryType what, 25 const struct mystr* p_log_str); 26static void vsf_log_do_log_wuftpd_format(struct vsf_session* p_sess, 27 struct mystr* p_str, int succeeded); 28static void vsf_log_do_log_to_file(int fd, struct mystr* p_str); 29 30void 31vsf_log_init(struct vsf_session* p_sess) 32{ 33 int retval; 34 if (tunable_syslog_enable || tunable_tcp_wrappers) 35 { 36 vsf_sysutil_openlog(); 37 } 38 if (!tunable_xferlog_enable && !tunable_dual_log_enable) 39 { 40 return; 41 } 42 if (tunable_dual_log_enable || tunable_xferlog_std_format) 43 { 44 retval = vsf_sysutil_create_or_open_file(tunable_xferlog_file, 0600); 45 if (vsf_sysutil_retval_is_error(retval)) 46 { 47 die2("failed to open xferlog log file:", tunable_xferlog_file); 48 } 49 p_sess->xferlog_fd = retval; 50 } 51 if (tunable_dual_log_enable || !tunable_xferlog_std_format) 52 { 53 if (!tunable_syslog_enable) 54 { 55 retval = vsf_sysutil_create_or_open_file(tunable_vsftpd_log_file, 0600); 56 if (vsf_sysutil_retval_is_error(retval)) 57 { 58 die2("failed to open vsftpd log file:", tunable_vsftpd_log_file); 59 } 60 p_sess->vsftpd_log_fd = retval; 61 } 62 } 63} 64 65static int 66vsf_log_type_is_transfer(enum EVSFLogEntryType type) 67{ 68 return (type == kVSFLogEntryDownload || type == kVSFLogEntryUpload); 69} 70 71void 72vsf_log_start_entry(struct vsf_session* p_sess, enum EVSFLogEntryType what) 73{ 74 if (p_sess->log_type != 0) 75 { 76 bug("non null log_type in vsf_log_start_entry"); 77 } 78 p_sess->log_type = (unsigned long) what; 79 p_sess->log_start_sec = 0; 80 p_sess->log_start_usec = 0; 81 p_sess->transfer_size = 0; 82 str_empty(&p_sess->log_str); 83 if (vsf_log_type_is_transfer(what)) 84 { 85 vsf_sysutil_update_cached_time(); 86 p_sess->log_start_sec = vsf_sysutil_get_cached_time_sec(); 87 p_sess->log_start_usec = vsf_sysutil_get_cached_time_usec(); 88 } 89} 90 91void 92vsf_log_line(struct vsf_session* p_sess, enum EVSFLogEntryType what, 93 struct mystr* p_str) 94{ 95 vsf_log_common(p_sess, 1, what, p_str); 96} 97 98int 99vsf_log_entry_pending(struct vsf_session* p_sess) 100{ 101 if (p_sess->log_type == 0) 102 { 103 return 0; 104 } 105 return 1; 106} 107 108void 109vsf_log_do_log(struct vsf_session* p_sess, int succeeded) 110{ 111 vsf_log_common(p_sess, succeeded, (enum EVSFLogEntryType) p_sess->log_type, 112 &p_sess->log_str); 113 p_sess->log_type = 0; 114} 115 116static void 117vsf_log_common(struct vsf_session* p_sess, int succeeded, 118 enum EVSFLogEntryType what, const struct mystr* p_str) 119{ 120 static struct mystr s_log_str; 121 /* Handle xferlog line if appropriate */ 122 if (p_sess->xferlog_fd != -1 && vsf_log_type_is_transfer(what)) 123 { 124 vsf_log_do_log_wuftpd_format(p_sess, &s_log_str, succeeded); 125 vsf_log_do_log_to_file(p_sess->xferlog_fd, &s_log_str); 126 } 127 /* Handle vsftpd.log line if appropriate */ 128 if (p_sess->vsftpd_log_fd != -1) 129 { 130 vsf_log_do_log_vsftpd_format(p_sess, &s_log_str, succeeded, what, p_str); 131 vsf_log_do_log_to_file(p_sess->vsftpd_log_fd, &s_log_str); 132 } 133 /* Handle syslog() line if appropriate */ 134 if (tunable_syslog_enable) 135 { 136 int severe = 0; 137 vsf_log_do_log_vsftpd_format(p_sess, &s_log_str, succeeded, what, p_str); 138 if (what == kVSFLogEntryLogin && !succeeded) 139 { 140 severe = 1; 141 } 142 str_syslog(&s_log_str, severe); 143 } 144} 145 146static void 147vsf_log_do_log_to_file(int fd, struct mystr* p_str) 148{ 149 if (!tunable_no_log_lock) 150 { 151 int retval = vsf_sysutil_lock_file_write(fd); 152 if (vsf_sysutil_retval_is_error(retval)) 153 { 154 return; 155 } 156 } 157 str_replace_unprintable(p_str, '?'); 158 str_append_char(p_str, '\n'); 159 /* Ignore write failure; maybe the disk filled etc. */ 160 (void) str_write_loop(p_str, fd); 161 if (!tunable_no_log_lock) 162 { 163 vsf_sysutil_unlock_file(fd); 164 } 165} 166 167static void 168vsf_log_do_log_wuftpd_format(struct vsf_session* p_sess, struct mystr* p_str, 169 int succeeded) 170{ 171 long delta_sec; 172 enum EVSFLogEntryType what = (enum EVSFLogEntryType) p_sess->log_type; 173 /* Date - vsf_sysutil_get_current_date updates cached time */ 174 str_alloc_text(p_str, vsf_sysutil_get_current_date()); 175 str_append_char(p_str, ' '); 176 /* Transfer time (in seconds) */ 177 delta_sec = vsf_sysutil_get_cached_time_sec() - p_sess->log_start_sec; 178 if (delta_sec <= 0) 179 { 180 delta_sec = 1; 181 } 182 str_append_ulong(p_str, (unsigned long) delta_sec); 183 str_append_char(p_str, ' '); 184 /* Remote host name */ 185 str_append_str(p_str, &p_sess->remote_ip_str); 186 str_append_char(p_str, ' '); 187 /* Bytes transferred */ 188 str_append_filesize_t(p_str, p_sess->transfer_size); 189 str_append_char(p_str, ' '); 190 /* Filename */ 191 str_append_str(p_str, &p_sess->log_str); 192 str_append_char(p_str, ' '); 193 /* Transfer type (ascii/binary) */ 194 if (p_sess->is_ascii) 195 { 196 str_append_text(p_str, "a "); 197 } 198 else 199 { 200 str_append_text(p_str, "b "); 201 } 202 /* Special action flag - tar, gzip etc. */ 203 str_append_text(p_str, "_ "); 204 /* Direction of transfer */ 205 if (what == kVSFLogEntryUpload) 206 { 207 str_append_text(p_str, "i "); 208 } 209 else 210 { 211 str_append_text(p_str, "o "); 212 } 213 /* Access mode: anonymous/real user, and identity */ 214 if (p_sess->is_anonymous) 215 { 216 str_append_text(p_str, "a "); 217 str_append_str(p_str, &p_sess->anon_pass_str); 218 } 219 else 220 { 221 str_append_text(p_str, "r "); 222 str_append_str(p_str, &p_sess->user_str); 223 } 224 str_append_char(p_str, ' '); 225 /* Service name, authentication method, authentication user id */ 226 str_append_text(p_str, "ftp 0 * "); 227 /* Completion status */ 228 if (succeeded) 229 { 230 str_append_char(p_str, 'c'); 231 } 232 else 233 { 234 str_append_char(p_str, 'i'); 235 } 236} 237 238static void 239vsf_log_do_log_vsftpd_format(struct vsf_session* p_sess, struct mystr* p_str, 240 int succeeded, enum EVSFLogEntryType what, 241 const struct mystr* p_log_str) 242{ 243 /* Date - vsf_sysutil_get_current_date updates cached time */ 244 str_alloc_text(p_str, vsf_sysutil_get_current_date()); 245 /* Pid */ 246 str_append_text(p_str, " [pid "); 247 str_append_ulong(p_str, vsf_sysutil_getpid()); 248 str_append_text(p_str, "] "); 249 /* User */ 250 if (!str_isempty(&p_sess->user_str)) 251 { 252 str_append_char(p_str, '['); 253 str_append_str(p_str, &p_sess->user_str); 254 str_append_text(p_str, "] "); 255 } 256 /* And the action */ 257 if (what != kVSFLogEntryFTPInput && what != kVSFLogEntryFTPOutput && 258 what != kVSFLogEntryConnection) 259 { 260 if (succeeded) 261 { 262 str_append_text(p_str, "OK "); 263 } 264 else 265 { 266 str_append_text(p_str, "FAIL "); 267 } 268 } 269 switch (what) 270 { 271 case kVSFLogEntryDownload: 272 str_append_text(p_str, "DOWNLOAD"); 273 break; 274 case kVSFLogEntryUpload: 275 str_append_text(p_str, "UPLOAD"); 276 break; 277 case kVSFLogEntryMkdir: 278 str_append_text(p_str, "MKDIR"); 279 break; 280 case kVSFLogEntryLogin: 281 str_append_text(p_str, "LOGIN"); 282 break; 283 case kVSFLogEntryFTPInput: 284 str_append_text(p_str, "FTP command"); 285 break; 286 case kVSFLogEntryFTPOutput: 287 str_append_text(p_str, "FTP response"); 288 break; 289 case kVSFLogEntryConnection: 290 str_append_text(p_str, "CONNECT"); 291 break; 292 case kVSFLogEntryDelete: 293 str_append_text(p_str, "DELETE"); 294 break; 295 case kVSFLogEntryRename: 296 str_append_text(p_str, "RENAME"); 297 break; 298 case kVSFLogEntryRmdir: 299 str_append_text(p_str, "RMDIR"); 300 break; 301 case kVSFLogEntryChmod: 302 str_append_text(p_str, "CHMOD"); 303 break; 304 default: 305 bug("bad entry_type in vsf_log_do_log"); 306 break; 307 } 308 str_append_text(p_str, ": Client \""); 309 str_append_str(p_str, &p_sess->remote_ip_str); 310 str_append_char(p_str, '"'); 311 if (what == kVSFLogEntryLogin && !str_isempty(&p_sess->anon_pass_str)) 312 { 313 str_append_text(p_str, ", anon password \""); 314 str_append_str(p_str, &p_sess->anon_pass_str); 315 str_append_char(p_str, '"'); 316 } 317 if (!str_isempty(p_log_str)) 318 { 319 str_append_text(p_str, ", \""); 320 str_append_str(p_str, p_log_str); 321 str_append_char(p_str, '"'); 322 } 323 if (what != kVSFLogEntryFTPInput && what != kVSFLogEntryFTPOutput) 324 { 325 if (p_sess->transfer_size) 326 { 327 str_append_text(p_str, ", "); 328 str_append_filesize_t(p_str, p_sess->transfer_size); 329 str_append_text(p_str, " bytes"); 330 } 331 if (vsf_log_type_is_transfer(what)) 332 { 333 long delta_sec = vsf_sysutil_get_cached_time_sec() - 334 p_sess->log_start_sec; 335 long delta_usec = vsf_sysutil_get_cached_time_usec() - 336 p_sess->log_start_usec; 337 double time_delta = (double) delta_sec + ((double) delta_usec / 338 (double) 1000000); 339 double kbyte_rate; 340 if (time_delta <= 0) 341 { 342 time_delta = 0.1; 343 } 344 kbyte_rate = 345 ((double) p_sess->transfer_size / time_delta) / (double) 1024; 346 str_append_text(p_str, ", "); 347 str_append_double(p_str, kbyte_rate); 348 str_append_text(p_str, "Kbyte/sec"); 349 } 350 } 351} 352 353