Coverage Report

Created: 2024-09-30 06:24

/src/proftpd/src/trace.c
Line
Count
Source (jump to first uncovered line)
1
/*
2
 * ProFTPD - FTP server daemon
3
 * Copyright (c) 2006-2022 The ProFTPD Project team
4
 *
5
 * This program is free software; you can redistribute it and/or modify
6
 * it under the terms of the GNU General Public License as published by
7
 * the Free Software Foundation; either version 2 of the License, or
8
 * (at your option) any later version.
9
 *
10
 * This program is distributed in the hope that it will be useful,
11
 * but WITHOUT ANY WARRANTY; without even the implied warranty of
12
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
13
 * GNU General Public License for more details.
14
 *
15
 * You should have received a copy of the GNU General Public License
16
 * along with this program; if not, write to the Free Software
17
 * Foundation, Inc., 51 Franklin Street, Suite 500, Boston, MA 02110-1335, USA.
18
 *
19
 * As a special exemption, the ProFTPD Project and other respective copyright
20
 * holders give permission to link this program with OpenSSL, and distribute
21
 * the resulting executable, without including the source code for OpenSSL
22
 * in the source distribution.
23
 */
24
25
/* Trace functions. */
26
27
#include "conf.h"
28
#include "privs.h"
29
30
#ifdef PR_USE_TRACE
31
32
#define TRACE_BUFFER_SIZE   (PR_TUNABLE_BUFFER_SIZE * 8)
33
34
static int trace_logfd = -1;
35
static unsigned long trace_opts = PR_TRACE_OPT_DEFAULT;
36
static pool *trace_pool = NULL;
37
static pr_table_t *trace_tab = NULL;
38
39
struct trace_levels {
40
  int min_level;
41
  int max_level;
42
};
43
44
static const char *trace_channels[] = {
45
  "auth",
46
  "binding",
47
  "command",
48
  "config",
49
  "ctrls",
50
  "data",
51
  "delay",
52
  "directory",
53
  "dns",
54
  "dso",
55
  "encode",
56
  "event",
57
  "facl",
58
  "fsio",
59
  "ident",
60
  "inet",
61
  "lock",
62
  "log",
63
  "module",
64
  "netacl",
65
  "netio",
66
  "pam",
67
  "pool",
68
  "regexp",
69
  "response",
70
  "scoreboard",
71
  "signal",
72
  "site",
73
  "timer",
74
  "var",
75
  "xfer",
76
  NULL
77
};
78
79
0
static void trace_restart_ev(const void *event_data, void *user_data) {
80
0
  trace_opts = PR_TRACE_OPT_DEFAULT;
81
82
0
  (void) close(trace_logfd);
83
0
  trace_logfd = -1;
84
85
0
  if (trace_pool != NULL) {
86
0
    destroy_pool(trace_pool);
87
0
    trace_pool = NULL;
88
0
    trace_tab = NULL;
89
90
0
    pr_event_unregister(NULL, "core.restart", trace_restart_ev);
91
0
  }
92
0
}
93
94
static int trace_write(const char *channel, int level, const char *msg,
95
0
    int discard) {
96
0
  pool *tmp_pool;
97
0
  char buf[TRACE_BUFFER_SIZE];
98
0
  size_t buflen = 0, len = 0;
99
0
  int use_conn_ips = FALSE;
100
101
0
  if (trace_logfd < 0) {
102
0
    return 0;
103
0
  }
104
105
0
  memset(buf, '\0', sizeof(buf));
106
0
  tmp_pool = make_sub_pool(trace_pool);
107
0
  pr_pool_tag(tmp_pool, "Trace message pool");
108
109
0
  if (trace_opts & PR_TRACE_OPT_USE_TIMESTAMP) {
110
0
    struct tm *tm;
111
112
0
    if (trace_opts & PR_TRACE_OPT_USE_TIMESTAMP_MILLIS) {
113
0
      struct timeval now;
114
0
      unsigned long millis;
115
116
0
      gettimeofday(&now, NULL);
117
0
      tm = pr_localtime(tmp_pool, (const time_t *) &(now.tv_sec));
118
119
0
      len = strftime(buf, sizeof(buf)-1, "%Y-%m-%d %H:%M:%S", tm);
120
0
      buflen = len;
121
122
      /* Convert microsecs to millisecs. */
123
0
      millis = now.tv_usec / 1000;
124
125
0
      len = pr_snprintf(buf + buflen, sizeof(buf) - buflen, ",%03lu ", millis);
126
0
      buflen += len;
127
128
0
    } else {
129
0
      time_t now;
130
131
0
      now = time(NULL);
132
0
      tm = pr_localtime(tmp_pool, &now);
133
134
0
      len = strftime(buf, sizeof(buf)-1, "%Y-%m-%d %H:%M:%S ", tm);
135
0
      buflen = len;
136
0
    }
137
0
  }
138
139
0
  if ((trace_opts & PR_TRACE_OPT_LOG_CONN_IPS) &&
140
0
      session.c != NULL) {
141
    /* We can only support the "+ConnIPs" TraceOption if there actually
142
     * is a client connected in this process.  We might be the daemon
143
     * process, in which there is no client.
144
     */
145
0
    use_conn_ips = TRUE;
146
0
  }
147
148
0
  if (use_conn_ips == FALSE) {
149
0
    len = pr_snprintf(buf + buflen, sizeof(buf) - buflen, "[%u] <%s:%d>: %s",
150
0
      (unsigned int) (session.pid ? session.pid : getpid()), channel, level,
151
0
      msg);
152
0
    buflen += len;
153
154
0
  } else {
155
0
    const char *client_ip, *server_ip;
156
0
    int server_port;
157
158
0
    client_ip = pr_netaddr_get_ipstr(session.c->remote_addr);
159
0
    server_ip = pr_netaddr_get_ipstr(session.c->local_addr);
160
0
    server_port = pr_netaddr_get_port(session.c->local_addr);
161
162
0
    len = pr_snprintf(buf + buflen, sizeof(buf) - buflen,
163
0
      "[%u] (client %s, server %s:%d) <%s:%d>: %s",
164
0
      (unsigned int) (session.pid ? session.pid : getpid()),
165
0
      client_ip != NULL ? client_ip : "none",
166
0
      server_ip != NULL ? server_ip : "none", server_port, channel, level, msg);
167
0
    buflen += len;
168
0
  }
169
170
0
  destroy_pool(tmp_pool);
171
0
  buf[sizeof(buf)-1] = '\0';
172
173
0
  if (buflen < (sizeof(buf) - 1)) {
174
0
    buf[buflen] = '\n';
175
0
    buflen++;
176
177
0
  } else {
178
0
    buf[sizeof(buf)-5] = '.';
179
0
    buf[sizeof(buf)-4] = '.';
180
0
    buf[sizeof(buf)-3] = '.';
181
0
    buf[sizeof(buf)-2] = '.';
182
0
    buflen = sizeof(buf)-1;
183
0
  }
184
185
0
  pr_log_event_generate(PR_LOG_TYPE_TRACELOG, trace_logfd, level, buf, buflen);
186
187
0
  if (discard) {
188
    /* This log message would not have been written to disk, so just discard
189
     * it.  The discard value is TRUE when there's a log listener for
190
     * TraceLog logging events, and the Trace log level configuration would
191
     * otherwise have filtered out this log message.
192
     */
193
0
    return 0;
194
0
  }
195
196
0
  return write(trace_logfd, buf, buflen);
197
0
}
198
199
0
pr_table_t *pr_trace_get_table(void) {
200
0
  if (trace_tab == NULL) {
201
0
    errno = ENOENT;
202
0
    return NULL;
203
0
  }
204
205
0
  return trace_tab;
206
0
}
207
208
0
static const struct trace_levels *trace_get_levels(const char *channel) {
209
0
  const void *value;
210
211
0
  if (channel == NULL) {
212
0
    errno = EINVAL;
213
0
    return NULL;
214
0
  }
215
216
0
  if (trace_tab == NULL ||
217
0
      trace_logfd < 0) {
218
0
    errno = EPERM;
219
0
    return NULL;
220
0
  }
221
222
0
  value = pr_table_get(trace_tab, channel, NULL);
223
0
  if (value == NULL) {
224
0
    errno = ENOENT;
225
0
    return NULL;
226
0
  }
227
228
0
  return value;
229
0
}
230
231
0
int pr_trace_get_level(const char *channel) {
232
0
  return pr_trace_get_max_level(channel);
233
0
}
234
235
0
int pr_trace_get_max_level(const char *channel) {
236
0
  const struct trace_levels *levels;
237
238
0
  levels = trace_get_levels(channel);
239
0
  if (levels == NULL) {
240
0
    return -1;
241
0
  }
242
243
0
  return levels->max_level;
244
0
}
245
246
0
int pr_trace_get_min_level(const char *channel) {
247
0
  const struct trace_levels *levels;
248
249
0
  levels = trace_get_levels(channel);
250
0
  if (levels == NULL) {
251
0
    return -1;
252
0
  }
253
254
0
  return levels->min_level;
255
0
}
256
257
0
int pr_trace_parse_levels(char *str, int *min_level, int *max_level) {
258
0
  int low = 1, high = -1;
259
0
  char *ptr = NULL, *tmp = NULL;
260
261
0
  if (str == NULL ||
262
0
      min_level == NULL ||
263
0
      max_level == NULL) {
264
0
    errno = EINVAL;
265
0
    return -1;
266
0
  }
267
268
  /* Watch for blank strings for levels (i.e. misconfigured/typo in config). */
269
0
  if (*str == '\0') {
270
0
    errno = EINVAL;
271
0
    return -1;
272
0
  }
273
274
  /* Check for a value range. */
275
0
  if (*str == '-') {
276
0
    errno = EINVAL;
277
0
    return -1;
278
0
  }
279
280
0
  ptr = strchr(str, '-');
281
0
  if (ptr == NULL) {
282
    /* Just a single value. */
283
0
    errno = 0;
284
0
    high = (int) strtol(str, &ptr, 10);
285
0
    if (errno == ERANGE) {
286
0
      errno = EINVAL;
287
0
      return -1;
288
0
    }
289
290
0
    if (ptr && *ptr) {
291
0
      errno = EINVAL;
292
0
      return -1;
293
0
    }
294
295
0
    if (high < 0) {
296
0
      errno = EINVAL;
297
0
      return -1;
298
0
    }
299
300
    /* A special case is where the single value is zero.  If this is the
301
     * case, we make sure that the min value is the same.
302
     */
303
0
    if (high != 0) {
304
0
      *min_level = 1;
305
306
0
    } else {
307
0
      *min_level = 0;
308
0
    }
309
310
0
    *max_level = high;
311
0
    return 0;
312
0
  }
313
314
  /* We have a range of values. */
315
0
  *ptr = '\0';
316
317
0
  low = (int) strtol(str, &tmp, 10);
318
0
  if (errno == ERANGE) {
319
0
    errno = EINVAL;
320
0
    return -1;
321
0
  }
322
323
0
  if (tmp && *tmp) {
324
0
    *ptr = '-';
325
0
    errno = EINVAL;
326
0
    return -1;
327
0
  }
328
0
  *ptr = '-';
329
330
0
  if (low < 0) {
331
0
    errno = EINVAL;
332
0
    return -1;
333
0
  }
334
335
0
  tmp = NULL;
336
0
  high = (int) strtol(ptr + 1, &tmp, 10);
337
0
  if (errno == ERANGE) {
338
0
    errno = EINVAL;
339
0
    return -1;
340
0
  }
341
342
0
  if (tmp && *tmp) {
343
0
    errno = EINVAL;
344
0
    return -1;
345
0
  }
346
347
0
  if (high < 0) {
348
0
    errno = EINVAL;
349
0
    return -1;
350
0
  }
351
352
0
  if (high < low) {
353
0
    errno = EINVAL;
354
0
    return -1;
355
0
  }
356
357
0
  *min_level = low;
358
0
  *max_level = high;
359
0
  return 0;
360
0
}
361
362
0
int pr_trace_set_file(const char *path) {
363
0
  int res, xerrno;
364
365
0
  if (path == NULL) {
366
0
    if (trace_logfd < 0) {
367
0
      errno = EINVAL;
368
0
      return -1;
369
0
    }
370
371
0
    (void) close(trace_logfd);
372
0
    trace_logfd = -1;
373
0
    return 0;
374
0
  }
375
376
0
  pr_signals_block();
377
0
  PRIVS_ROOT
378
0
  res = pr_log_openfile(path, &trace_logfd, 0660);
379
0
  xerrno = errno;
380
0
  PRIVS_RELINQUISH
381
0
  pr_signals_unblock();
382
383
0
  if (res < 0) {
384
0
    if (res == -1) {
385
0
      pr_log_debug(DEBUG1, "unable to open TraceLog '%s': %s", path,
386
0
        strerror(xerrno));
387
0
      errno = xerrno;
388
389
0
    } else if (res == PR_LOG_WRITABLE_DIR) {
390
0
      pr_log_debug(DEBUG1,
391
0
        "unable to open TraceLog '%s': parent directory is world-writable",
392
0
        path);
393
0
      errno = EPERM;
394
395
0
    } else if (res == PR_LOG_SYMLINK) {
396
0
      pr_log_debug(DEBUG1,
397
0
        "unable to open TraceLog '%s': cannot log to a symbolic link",
398
0
        path);
399
0
      errno = EPERM;
400
0
    }
401
402
0
    return res;
403
0
  }
404
405
0
  return 0;
406
0
}
407
408
0
int pr_trace_set_levels(const char *channel, int min_level, int max_level) {
409
0
  if (channel == NULL) {
410
0
    if (trace_tab == NULL) {
411
0
      errno = EINVAL;
412
0
      return -1;
413
0
    }
414
415
0
    return 0;
416
0
  }
417
418
0
  if (min_level > max_level) {
419
0
    errno = EINVAL;
420
0
    return -1;
421
0
  }
422
423
0
  if (trace_tab == NULL &&
424
0
      min_level < 0) {
425
0
    return 0;
426
0
  }
427
428
0
  if (trace_pool == NULL) {
429
0
    trace_pool = make_sub_pool(permanent_pool);
430
0
    pr_pool_tag(trace_pool, "Trace API");
431
432
0
    trace_tab = pr_table_alloc(trace_pool, 0);
433
434
    /* Register a handler for churning the log pool during HUP. */
435
0
    pr_event_register(NULL, "core.restart", trace_restart_ev, NULL);
436
0
  }
437
438
0
  if (min_level >= 0) {
439
0
    struct trace_levels *levels;
440
441
0
    levels = pcalloc(trace_pool, sizeof(struct trace_levels));
442
0
    levels->min_level = min_level;
443
0
    levels->max_level = max_level;
444
445
0
    if (strcmp(channel, PR_TRACE_DEFAULT_CHANNEL) != 0) {
446
0
      int count;
447
448
0
      count = pr_table_exists(trace_tab, channel);
449
0
      if (count <= 0) {
450
0
        if (pr_table_add(trace_tab, pstrdup(trace_pool, channel), levels,
451
0
            sizeof(struct trace_levels)) < 0) {
452
0
          return -1;
453
0
        }
454
455
0
      } else {
456
0
        if (pr_table_set(trace_tab, pstrdup(trace_pool, channel), levels,
457
0
            sizeof(struct trace_levels)) < 0) {
458
0
          return -1;
459
0
        }
460
0
      }
461
462
0
    } else {
463
0
      register unsigned int i;
464
465
0
      for (i = 0; trace_channels[i]; i++) {
466
0
        (void) pr_trace_set_levels(trace_channels[i], min_level, max_level);
467
0
      }
468
0
    }
469
470
0
  } else {
471
0
    if (strcmp(channel, PR_TRACE_DEFAULT_CHANNEL) != 0) {
472
0
      (void) pr_table_remove(trace_tab, channel, NULL);
473
474
0
    } else {
475
0
      register unsigned int i;
476
477
0
      for (i = 0; trace_channels[i]; i++) {
478
0
        (void) pr_table_remove(trace_tab, trace_channels[i], NULL);
479
0
      }
480
0
    }
481
0
  }
482
483
0
  return 0;
484
0
}
485
486
0
int pr_trace_set_options(unsigned long opts) {
487
0
  trace_opts = opts;
488
0
  return 0;
489
0
}
490
491
0
int pr_trace_use_stderr(int use_stderr) {
492
0
  if (use_stderr) {
493
0
    int res;
494
495
0
    res = dup(STDERR_FILENO);
496
0
    if (res < 0) {
497
0
      return -1;
498
0
    }
499
500
    /* Avoid a file descriptor leak by closing any existing fd. */
501
0
    (void) close(trace_logfd);
502
0
    trace_logfd = res;
503
504
0
  } else {
505
0
    (void) close(trace_logfd);
506
0
    trace_logfd = -1;
507
0
  }
508
509
0
  return 0;
510
0
}
511
512
1.42k
int pr_trace_msg(const char *channel, int level, const char *fmt, ...) {
513
1.42k
  int res;
514
1.42k
  va_list msg;
515
516
1.42k
  if (channel == NULL ||
517
1.42k
      fmt == NULL ||
518
1.42k
      level <= 0) {
519
0
    errno = EINVAL;
520
0
    return -1;
521
0
  }
522
523
  /* If no one's listening... */
524
1.42k
  if (trace_logfd < 0 &&
525
1.42k
      pr_log_event_listening(PR_LOG_TYPE_TRACELOG) <= 0) {
526
1.42k
    return 0;
527
1.42k
  }
528
529
0
  va_start(msg, fmt);
530
0
  res = pr_trace_vmsg(channel, level, fmt, msg);
531
0
  va_end(msg);
532
533
0
  return res;
534
1.42k
}
535
536
int pr_trace_vmsg(const char *channel, int level, const char *fmt,
537
0
    va_list msg) {
538
0
  char buf[TRACE_BUFFER_SIZE];
539
0
  const struct trace_levels *levels;
540
0
  int buflen, discard = FALSE, listening;
541
542
  /* Writing a trace message at level zero is NOT helpful; this makes it
543
   * impossible to quell messages to that trace channel by setting the level
544
   * filter to zero.  That being the case, treat level of zero as an invalid
545
   * level.
546
   */
547
548
0
  if (channel == NULL ||
549
0
      fmt == NULL ||
550
0
      level <= 0) {
551
0
    errno = EINVAL;
552
0
    return -1;
553
0
  }
554
555
0
  if (trace_tab == NULL) {
556
0
    errno = EPERM;
557
0
    return -1;
558
0
  }
559
560
  /* If no one's listening... */
561
0
  if (trace_logfd < 0) {
562
0
    return 0;
563
0
  }
564
565
0
  listening = pr_log_event_listening(PR_LOG_TYPE_TRACELOG);
566
567
0
  levels = trace_get_levels(channel);
568
0
  if (levels == NULL) {
569
0
    discard = TRUE;
570
571
0
    if (listening <= 0) {
572
0
      return 0;
573
0
    }
574
0
  }
575
576
0
  if (discard == FALSE &&
577
0
      level < levels->min_level) {
578
0
    discard = TRUE;
579
580
0
    if (listening <= 0) {
581
0
      return 0;
582
0
    }
583
0
  }
584
585
0
  if (discard == FALSE &&
586
0
      level > levels->max_level) {
587
0
    discard = TRUE;
588
589
0
    if (listening <= 0) {
590
0
      return 0;
591
0
    }
592
0
  }
593
594
0
  buflen = pr_vsnprintf(buf, sizeof(buf)-1, fmt, msg);
595
596
  /* Always make sure the buffer is NUL-terminated. */
597
0
  buf[sizeof(buf)-1] = '\0';
598
599
0
  if (buflen > 0 &&
600
0
      (size_t) buflen < sizeof(buf)) {
601
0
    buf[buflen] = '\0';
602
603
0
  } else {
604
    /* Note that vsnprintf() returns the number of characters _that would have
605
     * been printed if buffer were unlimited_.  Be careful of this.
606
     */
607
0
    buflen = sizeof(buf)-1;
608
0
  }
609
610
  /* Trim trailing newlines. */
611
0
  while (buflen >= 1 &&
612
0
         buf[buflen-1] == '\n') {
613
0
    pr_signals_handle();
614
0
    buf[buflen-1] = '\0';
615
0
    buflen--;
616
0
  }
617
618
0
  return trace_write(channel, level, buf, discard);
619
0
}
620
621
#else
622
623
pr_table_t *pr_trace_get_table(void) {
624
  errno = ENOSYS;
625
  return NULL;
626
}
627
628
int pr_trace_get_level(const char *channel) {
629
  errno = ENOSYS;
630
  return -1;
631
}
632
633
int pr_trace_get_max_level(const char *channel) {
634
  errno = ENOSYS;
635
  return -1;
636
}
637
638
int pr_trace_get_min_level(const char *channel) {
639
  errno = ENOSYS;
640
  return -1;
641
}
642
643
int pr_trace_parse_levels(char *str, int *min_level, int *max_level) {
644
  errno = ENOSYS;
645
  return -1;
646
}
647
648
int pr_trace_set_file(const char *path) {
649
  errno = ENOSYS;
650
  return -1;
651
}
652
653
int pr_trace_set_levels(const char *channel, int min_level, int max_level) {
654
  errno = ENOSYS;
655
  return -1;
656
}
657
658
int pr_trace_set_options(unsigned long opts) {
659
  errno = ENOSYS;
660
  return -1;
661
}
662
663
int pr_trace_msg(const char *channel, int level, const char *fmt, ...) {
664
  errno = ENOSYS;
665
  return -1;
666
}
667
668
int pr_trace_vmsg(const char *channel, int level, const char *fmt,
669
    va_list vargs) {
670
  errno = ENOSYS;
671
  return -1;
672
}
673
674
#endif /* PR_USE_TRACE */