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