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