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