TraceOptions directive are:
+ Timestamp option is enabled by default; the others
++are disabled by default.
+
+ + To enable an option, preface the option name with a '+' (plus) character; +--- doc/modules/mod_log.html ++++ doc/modules/mod_log.html +@@ -21,6 +21,7 @@ ProFTPD 1.3.x, and is compiled by +
E
+
+
+
++LogOptions
++Syntax: LogOptions opt1 ... optN
++Default: None
++Context: server config, <VirtualHost>, <Global>
++Module: mod_core
++Compatibility: 1.3.7rc4 and later
++
++
++The LogOptions directive can be used to change the format
++of the SystemLog messages, e.g.
++adding/remove certain fields of data. These options also apply to
++all module logging; ProFTPD logging is centralized, and the
++LogOptions are applied to any/all logging.
++
++
++The options supported by the LogOptions directive are:
++
++ - Hostname
++
- RoleBasedProcessLabels
++
- Timestamp
++
- VirtualHost
++
++All of these options are enabled by default, except for the
++RoleBasedProcessLabels option.
++
++
++To enable an option, preface the option name with a '+' (plus) character;
++to disable the option, use a '-' (minus) character prefix. For example:
++
++ # Log messages without timestamps or hostname
++ LogOptions -Hostname -Timestamp
++
++
++
++The RoleBasedProcessLabels option changes the label
++just for the PID, from e.g.:
++
++ proftpd[1234]
++
++to one of the following, depending on whether the process is the master
++daemon process, or a forked session process:
++
++ daemon[2345]
++ session[34567]
++
++This is useful, for example, when relying on systemd logging:
++
++ LogOptions -Timestamp -Hostname +RoleBasedProcessLabels
++
++
++
++
+ ServerLog
+ Syntax: ServerLog path|"none"
+ Default: None
+--- include/log.h
++++ include/log.h
+@@ -2,7 +2,7 @@
+ * ProFTPD - FTP server daemon
+ * Copyright (c) 1997, 1998 Public Flood Software
+ * Copyright (c) 1999, 2000 MacGyver aka Habeeb J. Dihu
+- * Copyright (c) 2001-2016 The ProFTPD Project team
++ * Copyright (c) 2001-2020 The ProFTPD Project team
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+@@ -99,7 +99,6 @@
+ # endif
+ #endif
+
+-
+ int log_lastlog(uid_t uid, const char *user_name, const char *tty,
+ const pr_netaddr_t *remote_addr);
+ #endif /* PR_USE_LASTLOG */
+@@ -224,4 +223,12 @@ int pr_log_event_listening(unsigned int
+ */
+ void pr_log_stacktrace(int fd, const char *name);
+
++/* Set options that affect the format of the logged messages. */
++int pr_log_set_options(unsigned long log_opts);
++#define PR_LOG_OPT_USE_TIMESTAMP 0x0001
++#define PR_LOG_OPT_USE_HOSTNAME 0x0002
++#define PR_LOG_OPT_USE_VHOST 0x0004
++#define PR_LOG_OPT_USE_ROLE_BASED_PROCESS_LABELS 0x0008
++#define PR_LOG_OPT_DEFAULT (PR_LOG_OPT_USE_TIMESTAMP|PR_LOG_OPT_USE_HOSTNAME|PR_LOG_OPT_USE_VHOST)
++
+ #endif /* PR_LOG_H */
+--- include/trace.h
++++ include/trace.h
+@@ -1,6 +1,6 @@
+ /*
+ * ProFTPD - FTP server daemon
+- * Copyright (c) 2006-2016 The ProFTPD Project team
++ * Copyright (c) 2006-2020 The ProFTPD Project team
+ *
+ * This program is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+@@ -50,8 +50,9 @@ int pr_trace_use_stderr(int);
+
+ int pr_trace_set_options(unsigned long trace_opts);
+ #define PR_TRACE_OPT_LOG_CONN_IPS 0x0001
+-#define PR_TRACE_OPT_USE_TIMESTAMP_MILLIS 0x0002
+-#define PR_TRACE_OPT_DEFAULT PR_TRACE_OPT_USE_TIMESTAMP_MILLIS
++#define PR_TRACE_OPT_USE_TIMESTAMP 0x0002
++#define PR_TRACE_OPT_USE_TIMESTAMP_MILLIS 0x0004
++#define PR_TRACE_OPT_DEFAULT (PR_TRACE_OPT_USE_TIMESTAMP|PR_TRACE_OPT_USE_TIMESTAMP_MILLIS)
+
+ int pr_trace_msg(const char *, int, const char *, ...)
+ #ifdef __GNUC__
+--- modules/mod_core.c
++++ modules/mod_core.c
+@@ -1695,7 +1695,7 @@ MODRET set_traceoptions(cmd_rec *cmd) {
+
+ opt++;
+
+- if (strncasecmp(opt, "ConnIPs", 8) == 0) {
++ if (strcasecmp(opt, "ConnIPs") == 0) {
+ switch (action) {
+ case '-':
+ trace_opts &= ~PR_TRACE_OPT_LOG_CONN_IPS;
+@@ -1706,7 +1706,18 @@ MODRET set_traceoptions(cmd_rec *cmd) {
+ break;
+ }
+
+- } else if (strncasecmp(opt, "TimestampMillis", 16) == 0) {
++ } else if (strcasecmp(opt, "Timestamp") == 0) {
++ switch (action) {
++ case '-':
++ trace_opts &= ~PR_TRACE_OPT_USE_TIMESTAMP;
++ break;
++
++ case '+':
++ trace_opts |= PR_TRACE_OPT_USE_TIMESTAMP;
++ break;
++ }
++
++ } else if (strcasecmp(opt, "TimestampMillis") == 0) {
+ switch (action) {
+ case '-':
+ trace_opts &= ~PR_TRACE_OPT_USE_TIMESTAMP_MILLIS;
+--- modules/mod_log.c
++++ modules/mod_log.c
+@@ -216,6 +216,104 @@ MODRET set_logformat(cmd_rec *cmd) {
+ return PR_HANDLED(cmd);
+ }
+
++/* usage: LogOptions opt1 ... */
++MODRET set_logoptions(cmd_rec *cmd) {
++ register unsigned int i;
++ int ctx;
++ unsigned long log_opts = PR_LOG_OPT_DEFAULT;
++ config_rec *c;
++
++ if (cmd->argc < 2) {
++ CONF_ERROR(cmd, "wrong number of parameters");
++ }
++
++ CHECK_CONF(cmd, CONF_ROOT|CONF_GLOBAL|CONF_VIRTUAL);
++
++ for (i = 1; i < cmd->argc; i++) {
++ char action, *opt;
++
++ opt = cmd->argv[i];
++ action = *opt;
++
++ if (action != '+' &&
++ action != '-') {
++ CONF_ERROR(cmd, pstrcat(cmd->tmp_pool, "bad LogOption: '", opt, "'",
++ NULL));
++ }
++
++ opt++;
++
++ if (strcasecmp(opt, "Timestamp") == 0) {
++ switch (action) {
++ case '-':
++ log_opts &= ~PR_LOG_OPT_USE_TIMESTAMP;
++ break;
++
++ case '+':
++ log_opts |= PR_LOG_OPT_USE_TIMESTAMP;
++ break;
++ }
++
++ } else if (strcasecmp(opt, "Hostname") == 0) {
++ switch (action) {
++ case '-':
++ log_opts &= ~PR_LOG_OPT_USE_HOSTNAME;
++ break;
++
++ case '+':
++ log_opts |= PR_LOG_OPT_USE_HOSTNAME;
++ break;
++ }
++
++ } else if (strcasecmp(opt, "VirtualHost") == 0) {
++ switch (action) {
++ case '-':
++ log_opts &= ~PR_LOG_OPT_USE_VHOST;
++ break;
++
++ case '+':
++ log_opts |= PR_LOG_OPT_USE_VHOST;
++ break;
++ }
++
++ } else if (strcasecmp(opt, "RoleBasedProcessLabels") == 0) {
++ switch (action) {
++ case '-':
++ log_opts &= ~PR_LOG_OPT_USE_ROLE_BASED_PROCESS_LABELS;
++ break;
++
++ case '+':
++ log_opts |= PR_LOG_OPT_USE_ROLE_BASED_PROCESS_LABELS;
++ break;
++ }
++
++ } else {
++ CONF_ERROR(cmd, pstrcat(cmd->tmp_pool, "unknown LogOption: '",
++ opt, "'", NULL));
++ }
++ }
++
++ c = add_config_param(cmd->argv[0], 1, NULL);
++ c->argv[0] = palloc(c->pool, sizeof(unsigned long));
++ *((unsigned long *) c->argv[0]) = log_opts;
++
++ ctx = (cmd->config && cmd->config->config_type != CONF_PARAM ?
++ cmd->config->config_type : cmd->server->config_type ?
++ cmd->server->config_type : CONF_ROOT);
++
++ if (ctx == CONF_ROOT) {
++ /* If we're the "server config" context, set the LogOptions here,
++ * too. This will apply these LogOptions to the daemon process.
++ */
++ if (pr_log_set_options(log_opts) < 0) {
++ pr_log_debug(DEBUG6, "%s: error setting LogOptions (%lu): %s",
++ (char *) cmd->argv[0], log_opts, strerror(errno));
++ }
++ }
++
++ return PR_HANDLED(cmd);
++}
++
+ /* Syntax: ExtendedLog file [ []] */
+ MODRET set_extendedlog(cmd_rec *cmd) {
+ config_rec *c = NULL;
+@@ -832,6 +930,9 @@ static void log_sess_reinit_ev(const voi
+ }
+ }
+
++ /* Restore original LogOptions settings. */
++ (void) pr_log_set_options(PR_LOG_OPT_DEFAULT);
++
+ res = log_sess_init();
+ if (res < 0) {
+ pr_session_disconnect(&log_module,
+@@ -1066,12 +1167,24 @@ MODRET log_post_pass(cmd_rec *cmd) {
+ static int dispatched_connect = FALSE;
+
+ static int log_sess_init(void) {
++ config_rec *c;
+ char *serverlog_name = NULL;
+ logfile_t *lf = NULL;
+
+ pr_event_register(&log_module, "core.session-reinit", log_sess_reinit_ev,
+ NULL);
+
++ c = find_config(main_server->conf, CONF_PARAM, "LogOptions", FALSE);
++ if (c != NULL) {
++ unsigned long log_opts;
++
++ log_opts = *((unsigned long *) c->argv[0]);
++ if (pr_log_set_options(log_opts) < 0) {
++ pr_log_debug(DEBUG6, "%s: error setting LogOptions (%lu): %s",
++ c->name, log_opts, strerror(errno));
++ }
++ }
++
+ /* Open the ServerLog, if present. */
+ serverlog_name = get_param_ptr(main_server->conf, "ServerLog", FALSE);
+ if (serverlog_name != NULL) {
+@@ -1238,6 +1351,7 @@ static conftable log_conftab[] = {
+ { "AllowLogSymlinks", set_allowlogsymlinks, NULL },
+ { "ExtendedLog", set_extendedlog, NULL },
+ { "LogFormat", set_logformat, NULL },
++ { "LogOptions", set_logoptions, NULL },
+ { "ServerLog", set_serverlog, NULL },
+ { "SystemLog", set_systemlog, NULL },
+ { NULL, NULL, NULL }
+--- src/ftpdctl.c
++++ src/ftpdctl.c
+@@ -35,6 +35,7 @@ static const char *program = "ftpdctl";
+
+ /* NOTE: these empty stubs are needed for proper linking. What a mess. */
+
++unsigned char is_master;
+ session_t session;
+ server_rec *main_server = NULL;
+
+--- src/log.c
++++ src/log.c
+@@ -34,8 +34,12 @@
+
+ #define LOGBUFFER_SIZE (PR_TUNABLE_PATH_MAX * 4)
+
++/* From src/main.c */
++extern unsigned char is_master;
++
+ static int syslog_open = FALSE;
+ static int syslog_discard = FALSE;
++static unsigned long log_opts = PR_LOG_OPT_DEFAULT;
+ static int logstderr = TRUE;
+ static int debug_level = DEBUG0;
+ static int default_level = PR_LOG_NOTICE;
+@@ -483,24 +487,26 @@ static void log_write(int priority, int
+ main_server->ServerFQDN) {
+ const pr_netaddr_t *remote_addr;
+ const char *remote_name;
++ size_t buflen = 0;
+
+ remote_addr = pr_netaddr_get_sess_remote_addr();
+ remote_name = pr_netaddr_get_sess_remote_name();
+
+- pr_snprintf(serverinfo, sizeof(serverinfo)-1, "%s",
+- main_server->ServerFQDN);
++ if (log_opts & PR_LOG_OPT_USE_VHOST) {
++ size_t len;
++
++ len = pr_snprintf(serverinfo, sizeof(serverinfo)-1, "%s",
++ main_server->ServerFQDN);
++ buflen += len;
++ }
++
+ serverinfo[sizeof(serverinfo)-1] = '\0';
+
+ if (remote_addr != NULL &&
+ remote_name != NULL) {
+- size_t serverinfo_len;
+-
+- serverinfo_len = strlen(serverinfo);
+-
+- pr_snprintf(serverinfo + serverinfo_len,
+- sizeof(serverinfo) - serverinfo_len, " (%s[%s])",
++ pr_snprintf(serverinfo + buflen, sizeof(serverinfo) - buflen,
++ "%s(%s[%s])", (log_opts & PR_LOG_OPT_USE_VHOST) ? " " : "",
+ remote_name, pr_netaddr_get_ipstr(remote_addr));
+-
+ serverinfo[sizeof(serverinfo)-1] = '\0';
+ }
+ }
+@@ -508,37 +514,63 @@ static void log_write(int priority, int
+ if (!discard &&
+ (logstderr || !main_server)) {
+ char buf[LOGBUFFER_SIZE] = {'\0'};
+- size_t buflen, len;
+- struct timeval now;
+- struct tm *tm = NULL;
+- unsigned long millis;
+-
+- gettimeofday(&now, NULL);
+- tm = pr_localtime(NULL, (const time_t *) &(now.tv_sec));
+- if (tm == NULL) {
+- return;
++ size_t buflen = 0, len = 0;
++ pid_t log_pid;
++ const char *process_label = "proftpd";
++
++ if (log_opts & PR_LOG_OPT_USE_TIMESTAMP) {
++ pool *tmp_pool;
++ struct timeval now;
++ struct tm *tm = NULL;
++ unsigned long millis;
++
++ tmp_pool = make_sub_pool(permanent_pool);
++ pr_pool_tag(tmp_pool, "Log message pool");
++
++ gettimeofday(&now, NULL);
++ tm = pr_localtime(tmp_pool, (const time_t *) &(now.tv_sec));
++ if (tm == NULL) {
++ destroy_pool(tmp_pool);
++ return;
++ }
++
++ len = strftime(buf, sizeof(buf)-1, "%Y-%m-%d %H:%M:%S", tm);
++ buflen = len;
++ buf[sizeof(buf)-1] = '\0';
++ destroy_pool(tmp_pool);
++
++ /* Convert microsecs to millisecs. */
++ millis = now.tv_usec / 1000;
++
++ len = pr_snprintf(buf + buflen, sizeof(buf) - len, ",%03lu ", millis);
++ buflen += len;
+ }
+
+- len = strftime(buf, sizeof(buf)-1, "%Y-%m-%d %H:%M:%S", tm);
+- buflen = len;
+- buf[sizeof(buf)-1] = '\0';
++ if (log_opts & PR_LOG_OPT_USE_HOSTNAME) {
++ len = pr_snprintf(buf + buflen, sizeof(buf) - buflen, "%s ",
++ systemlog_host);
++ buflen += len;
++ }
+
+- /* Convert microsecs to millisecs. */
+- millis = now.tv_usec / 1000;
++ log_pid = session.pid ? session.pid : getpid();
+
+- len = pr_snprintf(buf + buflen, sizeof(buf) - len, ",%03lu ", millis);
+- buflen += len;
+- buf[sizeof(buf)-1] = '\0';
++ if (log_opts & PR_LOG_OPT_USE_ROLE_BASED_PROCESS_LABELS) {
++ if (is_master) {
++ process_label = "daemon";
++
++ } else {
++ process_label = "session";
++ }
++ }
+
+ if (*serverinfo) {
+ len = pr_snprintf(buf + buflen, sizeof(buf) - buflen,
+- "%s proftpd[%u] %s: %s\n", systemlog_host,
+- (unsigned int) (session.pid ? session.pid : getpid()), serverinfo, s);
++ "%s[%u] %s: %s\n", process_label, (unsigned int) log_pid, serverinfo,
++ s);
+
+ } else {
+ len = pr_snprintf(buf + buflen, sizeof(buf) - buflen,
+- "%s proftpd[%u]: %s\n", systemlog_host,
+- (unsigned int) (session.pid ? session.pid : getpid()), s);
++ "%s[%u]: %s\n", process_label, (unsigned int) log_pid, s);
+ }
+
+ buflen += len;
+@@ -589,37 +621,65 @@ static void log_write(int priority, int
+
+ if (systemlog_fd != -1) {
+ char buf[LOGBUFFER_SIZE] = {'\0'};
+- size_t buflen, len;
+- struct timeval now;
+- struct tm *tm;
+- unsigned long millis;
+-
+- gettimeofday(&now, NULL);
+- tm = pr_localtime(NULL, (const time_t *) &(now.tv_sec));
+- if (tm == NULL) {
+- return;
++ size_t buflen = 0, len = 0;
++ pid_t log_pid;
++ const char *process_label = "proftpd";
++
++ if (log_opts & PR_LOG_OPT_USE_TIMESTAMP) {
++ pool *tmp_pool;
++ struct timeval now;
++ struct tm *tm;
++ unsigned long millis;
++
++ tmp_pool = make_sub_pool(permanent_pool);
++ pr_pool_tag(tmp_pool, "Log message pool");
++
++ gettimeofday(&now, NULL);
++ tm = pr_localtime(tmp_pool, (const time_t *) &(now.tv_sec));
++ if (tm == NULL) {
++ destroy_pool(tmp_pool);
++ return;
++ }
++
++ len = strftime(buf, sizeof(buf), "%Y-%m-%d %H:%M:%S", tm);
++ buflen = len;
++ buf[sizeof(buf) - 1] = '\0';
++ destroy_pool(tmp_pool);
++
++ /* Convert microsecs to millisecs. */
++ millis = now.tv_usec / 1000;
++
++ len = pr_snprintf(buf + buflen, sizeof(buf) - len, ",%03lu ", millis);
++ buflen += len;
+ }
+
+- len = strftime(buf, sizeof(buf), "%Y-%m-%d %H:%M:%S", tm);
+- buflen = len;
+ buf[sizeof(buf) - 1] = '\0';
+
+- /* Convert microsecs to millisecs. */
+- millis = now.tv_usec / 1000;
++ if (log_opts & PR_LOG_OPT_USE_HOSTNAME) {
++ len = pr_snprintf(buf + buflen, sizeof(buf) - buflen, "%s ",
++ systemlog_host);
++ buflen += len;
++ }
++
++ log_pid = session.pid ? session.pid : getpid();
+
+- len = pr_snprintf(buf + buflen, sizeof(buf) - len, ",%03lu ", millis);
+- buflen += len;
+- buf[sizeof(buf) - 1] = '\0';
++ if (log_opts & PR_LOG_OPT_USE_ROLE_BASED_PROCESS_LABELS) {
++ if (is_master) {
++ process_label = "daemon";
++
++ } else {
++ process_label = "session";
++ }
++ }
+
+ if (*serverinfo) {
+ len = pr_snprintf(buf + buflen, sizeof(buf) - buflen,
+- "%s proftpd[%u] %s: %s\n", systemlog_host,
+- (unsigned int) (session.pid ? session.pid : getpid()), serverinfo, s);
++ "%s[%u] %s: %s\n", process_label, (unsigned int) log_pid, serverinfo,
++ s);
+
+ } else {
+ len = pr_snprintf(buf + buflen, sizeof(buf) - buflen,
+- "%s proftpd[%u]: %s\n", systemlog_host,
+- (unsigned int) (session.pid ? session.pid : getpid()), s);
++ "%s[%u]: %s\n", process_label, (unsigned int) log_pid, s);
+ }
+
+ buflen += len;
+@@ -745,6 +805,11 @@ int pr_log_setdefaultlevel(int level) {
+ return old_level;
+ }
+
++int pr_log_set_options(unsigned long opts) {
++ log_opts = opts;
++ return 0;
++}
++
+ /* Convert a string into the matching syslog level value. Return -1
+ * if no matching level is found.
+ */
+--- src/trace.c
++++ src/trace.c
+@@ -93,7 +93,7 @@ static void trace_restart_ev(const void
+ static int trace_write(const char *channel, int level, const char *msg,
+ int discard) {
+ char buf[PR_TUNABLE_BUFFER_SIZE * 2];
+- size_t buflen, len;
++ size_t buflen = 0, len = 0;
+ struct tm *tm;
+ int use_conn_ips = FALSE;
+
+@@ -103,31 +103,32 @@ static int trace_write(const char *chann
+
+ memset(buf, '\0', sizeof(buf));
+
+- if (!(trace_opts & PR_TRACE_OPT_USE_TIMESTAMP_MILLIS)) {
+- time_t now;
++ if (trace_opts & PR_TRACE_OPT_USE_TIMESTAMP) {
++ if (trace_opts & PR_TRACE_OPT_USE_TIMESTAMP_MILLIS) {
++ struct timeval now;
++ unsigned long millis;
+
+- now = time(NULL);
+- tm = pr_localtime(NULL, &now);
++ gettimeofday(&now, NULL);
++ tm = pr_localtime(NULL, (const time_t *) &(now.tv_sec));
+
+- len = strftime(buf, sizeof(buf)-1, "%Y-%m-%d %H:%M:%S", tm);
+- buflen = len;
++ len = strftime(buf, sizeof(buf)-1, "%Y-%m-%d %H:%M:%S", tm);
++ buflen = len;
+
+- } else {
+- struct timeval now;
+- unsigned long millis;
+-
+- gettimeofday(&now, NULL);
++ /* Convert microsecs to millisecs. */
++ millis = now.tv_usec / 1000;
+
+- tm = pr_localtime(NULL, (const time_t *) &(now.tv_sec));
++ len = pr_snprintf(buf + buflen, sizeof(buf) - buflen, ",%03lu ", millis);
++ buflen += len;
+
+- len = strftime(buf, sizeof(buf)-1, "%Y-%m-%d %H:%M:%S", tm);
+- buflen = len;
++ } else {
++ time_t now;
+
+- /* Convert microsecs to millisecs. */
+- millis = now.tv_usec / 1000;
++ now = time(NULL);
++ tm = pr_localtime(NULL, &now);
+
+- len = pr_snprintf(buf + buflen, sizeof(buf) - buflen, ",%03lu", millis);
+- buflen += len;
++ len = strftime(buf, sizeof(buf)-1, "%Y-%m-%d %H:%M:%S ", tm);
++ buflen = len;
++ }
+ }
+
+ if ((trace_opts & PR_TRACE_OPT_LOG_CONN_IPS) &&
+@@ -140,7 +141,7 @@ static int trace_write(const char *chann
+ }
+
+ if (use_conn_ips == FALSE) {
+- len = pr_snprintf(buf + buflen, sizeof(buf) - buflen, " [%u] <%s:%d>: %s",
++ len = pr_snprintf(buf + buflen, sizeof(buf) - buflen, "[%u] <%s:%d>: %s",
+ (unsigned int) (session.pid ? session.pid : getpid()), channel, level,
+ msg);
+ buflen += len;
+@@ -154,7 +155,7 @@ static int trace_write(const char *chann
+ server_port = pr_netaddr_get_port(session.c->local_addr);
+
+ len = pr_snprintf(buf + buflen, sizeof(buf) - buflen,
+- " [%u] (client %s, server %s:%d) <%s:%d>: %s",
++ "[%u] (client %s, server %s:%d) <%s:%d>: %s",
+ (unsigned int) (session.pid ? session.pid : getpid()),
+ client_ip != NULL ? client_ip : "none",
+ server_ip != NULL ? server_ip : "none", server_port, channel, level, msg);
+--- tests/t/config/logoptions.t
++++ tests/t/config/logoptions.t
+@@ -0,0 +1,11 @@
++#!/usr/bin/env perl
++
++use lib qw(t/lib);
++use strict;
++
++use Test::Unit::HarnessUnit;
++
++$| = 1;
++
++my $r = Test::Unit::HarnessUnit->new();
++$r->start("ProFTPD::Tests::Config::LogOptions");
+--- tests/tests.pl
++++ tests/tests.pl
+@@ -141,6 +141,7 @@ if (scalar(@ARGV) > 0) {
+ t/config/ifdefine.t
+ t/config/include.t
+ t/config/listoptions.t
++ t/config/logoptions.t
+ t/config/masqueradeaddress.t
+ t/config/maxclients.t
+ t/config/maxclientsperclass.t
+--- tests/t/lib/ProFTPD/Tests/Config/LogOptions.pm
++++ tests/t/lib/ProFTPD/Tests/Config/LogOptions.pm
+@@ -0,0 +1,452 @@
++package ProFTPD::Tests::Config::LogOptions;
++
++use lib qw(t/lib);
++use base qw(ProFTPD::TestSuite::Child);
++use strict;
++
++use File::Spec;
++use IO::Handle;
++
++use ProFTPD::TestSuite::FTP;
++use ProFTPD::TestSuite::Utils qw(:auth :config :running :test :testsuite);
++
++$| = 1;
++
++my $order = 0;
++
++my $TESTS = {
++ logoptions_no_timestamp => {
++ order => ++$order,
++ test_class => [qw(forking)],
++ },
++
++ logoptions_no_hostname => {
++ order => ++$order,
++ test_class => [qw(forking)],
++ },
++
++ logoptions_no_virtualhost => {
++ order => ++$order,
++ test_class => [qw(forking)],
++ },
++
++ logoptions_use_rolebasedprocesslabels => {
++ order => ++$order,
++ test_class => [qw(forking)],
++ },
++};
++
++sub new {
++ return shift()->SUPER::new(@_);
++}
++
++sub list_tests {
++ return testsuite_get_runnable_tests($TESTS);
++}
++
++sub logoptions_no_timestamp {
++ my $self = shift;
++ my $tmpdir = $self->{tmpdir};
++ my $setup = test_setup($tmpdir, 'log');
++
++ my $config = {
++ PidFile => $setup->{pid_file},
++ ScoreboardFile => $setup->{scoreboard_file},
++ SystemLog => $setup->{log_file},
++
++ AuthUserFile => $setup->{auth_user_file},
++ AuthGroupFile => $setup->{auth_group_file},
++
++ LogOptions => '-Timestamp',
++
++ IfModules => {
++ 'mod_delay.c' => {
++ DelayEngine => 'off',
++ },
++ },
++ };
++
++ my ($port, $config_user, $config_group) = config_write($setup->{config_file},
++ $config);
++
++ # Open pipes, for use between the parent and child processes. Specifically,
++ # the child will indicate when it's done with its test by writing a message
++ # to the parent.
++ my ($rfh, $wfh);
++ unless (pipe($rfh, $wfh)) {
++ die("Can't open pipe: $!");
++ }
++
++ my $ex;
++
++ # Fork child
++ $self->handle_sigchld();
++ defined(my $pid = fork()) or die("Can't fork: $!");
++ if ($pid) {
++ eval {
++ my $client = ProFTPD::TestSuite::FTP->new('127.0.0.1', $port);
++ $client->login($setup->{user}, $setup->{passwd});
++ $client->quit();
++ };
++ if ($@) {
++ $ex = $@;
++ }
++
++ $wfh->print("done\n");
++ $wfh->flush();
++
++ } else {
++ eval { server_wait($setup->{config_file}, $rfh) };
++ if ($@) {
++ warn($@);
++ exit 1;
++ }
++
++ exit 0;
++ }
++
++ # Stop server
++ server_stop($setup->{pid_file});
++ $self->assert_child_ok($pid);
++
++ eval {
++ if (open(my $fh, "< $setup->{log_file}")) {
++ my $ok = 0;
++
++ while (my $line = <$fh>) {
++ chomp($line);
++
++ if ($ENV{TEST_VERBOSE}) {
++ print STDERR "# $line\n";
++ }
++
++ my $expected = '^\S+ proftpd\[\d+\] .*?$';
++
++ if ($line =~ /$expected/) {
++ $ok = 1;
++ last;
++ }
++ }
++
++ close($fh);
++
++ $self->assert($ok, test_msg("Missing expected LogOptions messages"));
++
++ } else {
++ die("Can't read $setup->{log_file}: $!");
++ }
++ };
++ if ($@) {
++ $ex = $@;
++ }
++
++ test_cleanup($setup->{log_file}, $ex);
++}
++
++sub logoptions_no_hostname {
++ my $self = shift;
++ my $tmpdir = $self->{tmpdir};
++ my $setup = test_setup($tmpdir, 'log');
++
++ my $config = {
++ PidFile => $setup->{pid_file},
++ ScoreboardFile => $setup->{scoreboard_file},
++ SystemLog => $setup->{log_file},
++
++ AuthUserFile => $setup->{auth_user_file},
++ AuthGroupFile => $setup->{auth_group_file},
++
++ LogOptions => '-Hostname',
++
++ IfModules => {
++ 'mod_delay.c' => {
++ DelayEngine => 'off',
++ },
++ },
++ };
++
++ my ($port, $config_user, $config_group) = config_write($setup->{config_file},
++ $config);
++
++ # Open pipes, for use between the parent and child processes. Specifically,
++ # the child will indicate when it's done with its test by writing a message
++ # to the parent.
++ my ($rfh, $wfh);
++ unless (pipe($rfh, $wfh)) {
++ die("Can't open pipe: $!");
++ }
++
++ my $ex;
++
++ # Fork child
++ $self->handle_sigchld();
++ defined(my $pid = fork()) or die("Can't fork: $!");
++ if ($pid) {
++ eval {
++ my $client = ProFTPD::TestSuite::FTP->new('127.0.0.1', $port);
++ $client->login($setup->{user}, $setup->{passwd});
++ $client->quit();
++ };
++ if ($@) {
++ $ex = $@;
++ }
++
++ $wfh->print("done\n");
++ $wfh->flush();
++
++ } else {
++ eval { server_wait($setup->{config_file}, $rfh) };
++ if ($@) {
++ warn($@);
++ exit 1;
++ }
++
++ exit 0;
++ }
++
++ # Stop server
++ server_stop($setup->{pid_file});
++ $self->assert_child_ok($pid);
++
++ eval {
++ if (open(my $fh, "< $setup->{log_file}")) {
++ my $ok = 0;
++
++ while (my $line = <$fh>) {
++ chomp($line);
++
++ if ($ENV{TEST_VERBOSE}) {
++ print STDERR "# $line\n";
++ }
++
++ my $expected = '^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3} proftpd\[\d+\] .*?$';
++
++ if ($line =~ /$expected/) {
++ my $pid = $1;
++ $ok = 1;
++ last;
++ }
++ }
++
++ close($fh);
++
++ $self->assert($ok, test_msg("Missing expected LogOptions messages"));
++
++ } else {
++ die("Can't read $setup->{log_file}: $!");
++ }
++ };
++ if ($@) {
++ $ex = $@;
++ }
++
++ test_cleanup($setup->{log_file}, $ex);
++}
++
++sub logoptions_no_virtualhost {
++ my $self = shift;
++ my $tmpdir = $self->{tmpdir};
++ my $setup = test_setup($tmpdir, 'log');
++
++ my $config = {
++ PidFile => $setup->{pid_file},
++ ScoreboardFile => $setup->{scoreboard_file},
++ SystemLog => $setup->{log_file},
++
++ AuthUserFile => $setup->{auth_user_file},
++ AuthGroupFile => $setup->{auth_group_file},
++
++ LogOptions => '-VirtualHost',
++
++ IfModules => {
++ 'mod_delay.c' => {
++ DelayEngine => 'off',
++ },
++ },
++ };
++
++ my ($port, $config_user, $config_group) = config_write($setup->{config_file},
++ $config);
++
++ # Open pipes, for use between the parent and child processes. Specifically,
++ # the child will indicate when it's done with its test by writing a message
++ # to the parent.
++ my ($rfh, $wfh);
++ unless (pipe($rfh, $wfh)) {
++ die("Can't open pipe: $!");
++ }
++
++ my $ex;
++
++ # Fork child
++ $self->handle_sigchld();
++ defined(my $pid = fork()) or die("Can't fork: $!");
++ if ($pid) {
++ eval {
++ my $client = ProFTPD::TestSuite::FTP->new('127.0.0.1', $port);
++ $client->login($setup->{user}, $setup->{passwd});
++ $client->quit();
++ };
++ if ($@) {
++ $ex = $@;
++ }
++
++ $wfh->print("done\n");
++ $wfh->flush();
++
++ } else {
++ eval { server_wait($setup->{config_file}, $rfh) };
++ if ($@) {
++ warn($@);
++ exit 1;
++ }
++
++ exit 0;
++ }
++
++ # Stop server
++ server_stop($setup->{pid_file});
++ $self->assert_child_ok($pid);
++
++ eval {
++ if (open(my $fh, "< $setup->{log_file}")) {
++ my $ok = 0;
++
++ while (my $line = <$fh>) {
++ chomp($line);
++
++ if ($ENV{TEST_VERBOSE}) {
++ print STDERR "# $line\n";
++ }
++
++ my $expected = '^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3} \S+ proftpd\[\d+\] \(.*?$';
++
++ if ($line =~ /$expected/) {
++ $ok = 1;
++ last;
++ }
++ }
++
++ close($fh);
++
++ $self->assert($ok, test_msg("Missing expected LogOptions messages"));
++
++ } else {
++ die("Can't read $setup->{log_file}: $!");
++ }
++ };
++ if ($@) {
++ $ex = $@;
++ }
++
++ test_cleanup($setup->{log_file}, $ex);
++}
++
++sub logoptions_use_rolebasedprocesslabels {
++ my $self = shift;
++ my $tmpdir = $self->{tmpdir};
++ my $setup = test_setup($tmpdir, 'log');
++
++ my $config = {
++ PidFile => $setup->{pid_file},
++ ScoreboardFile => $setup->{scoreboard_file},
++ SystemLog => $setup->{log_file},
++
++ AuthUserFile => $setup->{auth_user_file},
++ AuthGroupFile => $setup->{auth_group_file},
++
++ LogOptions => '+RoleBasedProcessLabels',
++
++ IfModules => {
++ 'mod_delay.c' => {
++ DelayEngine => 'off',
++ },
++ },
++ };
++
++ my ($port, $config_user, $config_group) = config_write($setup->{config_file},
++ $config);
++
++ # Open pipes, for use between the parent and child processes. Specifically,
++ # the child will indicate when it's done with its test by writing a message
++ # to the parent.
++ my ($rfh, $wfh);
++ unless (pipe($rfh, $wfh)) {
++ die("Can't open pipe: $!");
++ }
++ my $ex;
++ # Fork child
++ $self->handle_sigchld();
++ defined(my $pid = fork()) or die("Can't fork: $!");
++ if ($pid) {
++ eval {
++ my $client = ProFTPD::TestSuite::FTP->new('127.0.0.1', $port);
++ $client->login($setup->{user}, $setup->{passwd});
++ $client->quit();
++ };
++ if ($@) {
++ $ex = $@;
++ }
++
++ $wfh->print("done\n");
++ $wfh->flush();
++
++ } else {
++ eval { server_wait($setup->{config_file}, $rfh) };
++ if ($@) {
++ warn($@);
++ exit 1;
++ }
++
++ exit 0;
++ }
++
++ # Stop server
++ server_stop($setup->{pid_file});
++ $self->assert_child_ok($pid);
++
++ eval {
++ if (open(my $fh, "< $setup->{log_file}")) {
++ my $saw_daemon_label = 0;
++ my $saw_session_label = 0;
++
++ while (my $line = <$fh>) {
++ chomp($line);
++
++ if ($ENV{TEST_VERBOSE}) {
++ print STDERR "# $line\n";
++ }
++
++ my $expected = '^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3} \S+ daemon\[\d+\] ';
++ if ($line =~ /$expected/) {
++ $saw_daemon_label = 1;
++ }
++
++ $expected = '^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3} \S+ session\[\d+\] ';
++ if ($line =~ /$expected/) {
++ $saw_session_label = 1;
++ }
++
++ if ($saw_daemon_label == 1 &&
++ $saw_session_label) {
++ last;
++ }
++ }
++
++ close($fh);
++
++ $self->assert($saw_daemon_label && $saw_session_label,
++ test_msg("Missing expected LogOptions messages"));
++
++ } else {
++ die("Can't read $setup->{log_file}: $!");
++ }
++ };
++ if ($@) {
++ $ex = $@;
++ }
++
++ test_cleanup($setup->{log_file}, $ex);
++}
++
++1;
+--- tests/t/lib/ProFTPD/Tests/Config/TraceOptions.pm
++++ tests/t/lib/ProFTPD/Tests/Config/TraceOptions.pm
+@@ -24,6 +24,11 @@ my $TESTS = {
+ order => ++$order,
+ test_class => [qw(feature_trace forking)],
+ },
++
++ traceoptions_no_timestamp => {
++ order => ++$order,
++ test_class => [qw(feature_trace forking)],
++ },
+ };
+
+ sub new {
+@@ -37,51 +42,137 @@ sub list_tests {
+ sub traceoptions_conn_ips {
+ my $self = shift;
+ my $tmpdir = $self->{tmpdir};
++ my $setup = test_setup($tmpdir, 'trace');
++
++ my $trace_log = File::Spec->rel2abs("$tmpdir/trace.log");
++
++ my $config = {
++ PidFile => $setup->{pid_file},
++ ScoreboardFile => $setup->{scoreboard_file},
++ SystemLog => $setup->{log_file},
++ TraceLog => $trace_log,
++ Trace => 'DEFAULT:10',
++ TraceOptions => '+ConnIPs',
++
++ AuthUserFile => $setup->{auth_user_file},
++ AuthGroupFile => $setup->{auth_group_file},
++
++ IfModules => {
++ 'mod_delay.c' => {
++ DelayEngine => 'off',
++ },
++ },
++ };
++
++ my ($port, $config_user, $config_group) = config_write($setup->{config_file},
++ $config);
++
++ # Open pipes, for use between the parent and child processes. Specifically,
++ # the child will indicate when it's done with its test by writing a message
++ # to the parent.
++ my ($rfh, $wfh);
++ unless (pipe($rfh, $wfh)) {
++ die("Can't open pipe: $!");
++ }
++
++ my $ex;
+
+- my $config_file = "$tmpdir/trace.conf";
+- my $pid_file = File::Spec->rel2abs("$tmpdir/trace.pid");
+- my $scoreboard_file = File::Spec->rel2abs("$tmpdir/trace.scoreboard");
+-
+- my $log_file = File::Spec->rel2abs('tests.log');
+-
+- my $auth_user_file = File::Spec->rel2abs("$tmpdir/trace.passwd");
+- my $auth_group_file = File::Spec->rel2abs("$tmpdir/trace.group");
+-
+- my $user = 'proftpd';
+- my $passwd = 'test';
+- my $group = 'ftpd';
+- my $home_dir = File::Spec->rel2abs($tmpdir);
+- my $uid = 500;
+- my $gid = 500;
+-
+- # Make sure that, if we're running as root, that the home directory has
+- # permissions/privs set for the account we create
+- if ($< == 0) {
+- unless (chmod(0755, $home_dir)) {
+- die("Can't set perms on $home_dir to 0755: $!");
++ # Fork child
++ $self->handle_sigchld();
++ defined(my $pid = fork()) or die("Can't fork: $!");
++ if ($pid) {
++ eval {
++ my $client = ProFTPD::TestSuite::FTP->new('127.0.0.1', $port);
++ $client->login($setup->{user}, $setup->{passwd});
++ $client->quit();
++ };
++ if ($@) {
++ $ex = $@;
++ }
++
++ $wfh->print("done\n");
++ $wfh->flush();
++
++ } else {
++ eval { server_wait($setup->{config_file}, $rfh) };
++ if ($@) {
++ warn($@);
++ exit 1;
+ }
+
+- unless (chown($uid, $gid, $home_dir)) {
+- die("Can't set owner of $home_dir to $uid/$gid: $!");
++ exit 0;
++ }
++
++ # Stop server
++ server_stop($setup->{pid_file});
++ $self->assert_child_ok($pid);
++
++ eval {
++ if (open(my $fh, "< $trace_log")) {
++ my $ok = 0;
++
++ while (my $line = <$fh>) {
++ chomp($line);
++
++ my $expected = '\[\d+\]\s+\(client\s+(\S+), server\s+\S+\)\s+<(\S+):(\d+)>: (.*?)$';
++
++ if ($line =~ /$expected/) {
++ my $client_ip = $1;
++ my $trace_channel = $2;
++ my $trace_level = $3;
++ my $trace_msg = $4;
++
++ next unless $trace_channel eq 'command';
++
++ my $expected = 'command';
++ $self->assert($expected eq $trace_channel,
++ test_msg("Expected '$expected', got '$trace_channel'"));
++
++ $expected = 7;
++ $self->assert($expected >= $trace_level,
++ test_msg("Expected >= $expected, got $trace_level"));
++
++ $expected = '127.0.0.1';
++ $self->assert($expected eq $client_ip,
++ test_msg("Expected '$expected', got '$client_ip'"));
++
++ $ok = 1;
++ last;
++ }
++ }
++
++ close($fh);
++
++ $self->assert($ok, test_msg("Missing expected TraceLog messages"));
++
++ } else {
++ die("Can't read $trace_log: $!");
+ }
++ };
++ if ($@) {
++ $ex = $@;
+ }
+
+- auth_user_write($auth_user_file, $user, $passwd, $uid, $gid, $home_dir,
+- '/bin/bash');
+- auth_group_write($auth_group_file, $group, $gid, $user);
++ test_cleanup($setup->{log_file}, $ex);
++}
++
++sub traceoptions_timestamp_millis {
++ my $self = shift;
++ my $tmpdir = $self->{tmpdir};
++ my $setup = test_setup($tmpdir, 'trace');
+
+ my $trace_log = File::Spec->rel2abs("$tmpdir/trace.log");
+
+ my $config = {
+- PidFile => $pid_file,
+- ScoreboardFile => $scoreboard_file,
+- SystemLog => $log_file,
++ PidFile => $setup->{pid_file},
++ ScoreboardFile => $setup->{scoreboard_file},
++ SystemLog => $setup->{log_file},
+ TraceLog => $trace_log,
+ Trace => 'DEFAULT:10',
+- TraceOptions => '+ConnIPs',
++ TraceOptions => '+TimestampMillis',
+
+- AuthUserFile => $auth_user_file,
+- AuthGroupFile => $auth_group_file,
++ AuthUserFile => $setup->{auth_user_file},
++ AuthGroupFile => $setup->{auth_group_file},
+
+ IfModules => {
+ 'mod_delay.c' => {
+@@ -90,7 +181,8 @@ sub traceoptions_conn_ips {
+ },
+ };
+
+- my ($port, $config_user, $config_group) = config_write($config_file, $config);
++ my ($port, $config_user, $config_group) = config_write($setup->{config_file},
++ $config);
+
+ # Open pipes, for use between the parent and child processes. Specifically,
+ # the child will indicate when it's done with its test by writing a message
+@@ -108,10 +200,9 @@ sub traceoptions_conn_ips {
+ if ($pid) {
+ eval {
+ my $client = ProFTPD::TestSuite::FTP->new('127.0.0.1', $port);
+- $client->login($user, $passwd);
++ $client->login($setup->{user}, $setup->{passwd});
+ $client->quit();
+ };
+-
+ if ($@) {
+ $ex = $@;
+ }
+@@ -120,7 +211,7 @@ sub traceoptions_conn_ips {
+ $wfh->flush();
+
+ } else {
+- eval { server_wait($config_file, $rfh) };
++ eval { server_wait($setup->{config_file}, $rfh) };
+ if ($@) {
+ warn($@);
+ exit 1;
+@@ -130,106 +221,74 @@ sub traceoptions_conn_ips {
+ }
+
+ # Stop server
+- server_stop($pid_file);
+-
++ server_stop($setup->{pid_file});
+ $self->assert_child_ok($pid);
+
+- if (open(my $fh, "< $trace_log")) {
+- my $ok = 0;
++ eval {
++ if (open(my $fh, "< $trace_log")) {
++ my $ok = 0;
+
+- while (my $line = <$fh>) {
+- chomp($line);
++ while (my $line = <$fh>) {
++ chomp($line);
+
+- my $expected = '\[\d+\]\s+\(client\s+(\S+), server\s+\S+\)\s+<(\S+):(\d+)>: (.*?)$';
++ if ($ENV{TEST_VERBOSE}) {
++ print STDERR "# $line\n";
++ }
+
+- if ($line =~ /$expected/) {
+- my $client_ip = $1;
+- my $trace_channel = $2;
+- my $trace_level = $3;
+- my $trace_msg = $4;
++ my $expected = '\d+:\d+:\d+,\d+\s+\[\d+\]\s+<(\S+):(\d+)>: (.*?)$';
+
+- next unless $trace_channel eq 'command';
++ if ($line =~ /$expected/) {
++ my $trace_channel = $1;
++ my $trace_level = $2;
++ my $trace_msg = $3;
+
+- my $expected = 'command';
+- $self->assert($expected eq $trace_channel,
+- test_msg("Expected '$expected', got '$trace_channel'"));
++ next unless $trace_channel eq 'command';
+
+- $expected = 7;
+- $self->assert($expected >= $trace_level,
+- test_msg("Expected >= $expected, got $trace_level"));
++ my $expected = 'command';
++ $self->assert($expected eq $trace_channel,
++ test_msg("Expected '$expected', got '$trace_channel'"));
+
+- $expected = '127.0.0.1';
+- $self->assert($expected eq $client_ip,
+- test_msg("Expected '$expected', got '$client_ip'"));
++ $expected = 7;
++ $self->assert($expected >= $trace_level,
++ test_msg("Expected >= $expected, got $trace_level"));
+
+- $ok = 1;
+- last;
++ $ok = 1;
++ last;
++ }
+ }
+- }
+-
+- close($fh);
+
+- $self->assert($ok, test_msg("Missing expected TraceLog messages"));
++ close($fh);
+
+- } else {
+- die("Can't read $trace_log: $!");
+- }
++ $self->assert($ok, test_msg("Missing expected TraceLog messages"));
+
+- if ($ex) {
+- die($ex);
++ } else {
++ die("Can't read $trace_log: $!");
++ }
++ };
++ if ($@) {
++ $ex = $@;
+ }
+
+- unlink($log_file);
++ test_cleanup($setup->{log_file}, $ex);
+ }
+
+-sub traceoptions_timestamp_millis {
++sub traceoptions_no_timestamp {
+ my $self = shift;
+ my $tmpdir = $self->{tmpdir};
+-
+- my $config_file = "$tmpdir/trace.conf";
+- my $pid_file = File::Spec->rel2abs("$tmpdir/trace.pid");
+- my $scoreboard_file = File::Spec->rel2abs("$tmpdir/trace.scoreboard");
+-
+- my $log_file = File::Spec->rel2abs('tests.log');
+-
+- my $auth_user_file = File::Spec->rel2abs("$tmpdir/trace.passwd");
+- my $auth_group_file = File::Spec->rel2abs("$tmpdir/trace.group");
+-
+- my $user = 'proftpd';
+- my $passwd = 'test';
+- my $group = 'ftpd';
+- my $home_dir = File::Spec->rel2abs($tmpdir);
+- my $uid = 500;
+- my $gid = 500;
+-
+- # Make sure that, if we're running as root, that the home directory has
+- # permissions/privs set for the account we create
+- if ($< == 0) {
+- unless (chmod(0755, $home_dir)) {
+- die("Can't set perms on $home_dir to 0755: $!");
+- }
+-
+- unless (chown($uid, $gid, $home_dir)) {
+- die("Can't set owner of $home_dir to $uid/$gid: $!");
+- }
+- }
+-
+- auth_user_write($auth_user_file, $user, $passwd, $uid, $gid, $home_dir,
+- '/bin/bash');
+- auth_group_write($auth_group_file, $group, $gid, $user);
++ my $setup = test_setup($tmpdir, 'trace');
+
+ my $trace_log = File::Spec->rel2abs("$tmpdir/trace.log");
+
+ my $config = {
+- PidFile => $pid_file,
+- ScoreboardFile => $scoreboard_file,
+- SystemLog => $log_file,
++ PidFile => $setup->{pid_file},
++ ScoreboardFile => $setup->{scoreboard_file},
++ SystemLog => $setup->{log_file},
+ TraceLog => $trace_log,
+ Trace => 'DEFAULT:10',
+- TraceOptions => '+TimestampMillis',
++ TraceOptions => '-Timestamp',
+
+- AuthUserFile => $auth_user_file,
+- AuthGroupFile => $auth_group_file,
++ AuthUserFile => $setup->{auth_user_file},
++ AuthGroupFile => $setup->{auth_group_file},
+
+ IfModules => {
+ 'mod_delay.c' => {
+@@ -238,7 +297,8 @@ sub traceoptions_timestamp_millis {
+ },
+ };
+
+- my ($port, $config_user, $config_group) = config_write($config_file, $config);
++ my ($port, $config_user, $config_group) = config_write($setup->{config_file},
++ $config);
+
+ # Open pipes, for use between the parent and child processes. Specifically,
+ # the child will indicate when it's done with its test by writing a message
+@@ -256,10 +316,9 @@ sub traceoptions_timestamp_millis {
+ if ($pid) {
+ eval {
+ my $client = ProFTPD::TestSuite::FTP->new('127.0.0.1', $port);
+- $client->login($user, $passwd);
++ $client->login($setup->{user}, $setup->{passwd});
+ $client->quit();
+ };
+-
+ if ($@) {
+ $ex = $@;
+ }
+@@ -268,7 +327,7 @@ sub traceoptions_timestamp_millis {
+ $wfh->flush();
+
+ } else {
+- eval { server_wait($config_file, $rfh) };
++ eval { server_wait($setup->{config_file}, $rfh) };
+ if ($@) {
+ warn($@);
+ exit 1;
+@@ -278,51 +337,55 @@ sub traceoptions_timestamp_millis {
+ }
+
+ # Stop server
+- server_stop($pid_file);
+-
++ server_stop($setup->{pid_file});
+ $self->assert_child_ok($pid);
+
+- if (open(my $fh, "< $trace_log")) {
+- my $ok = 0;
++ eval {
++ if (open(my $fh, "< $trace_log")) {
++ my $ok = 0;
+
+- while (my $line = <$fh>) {
+- chomp($line);
++ while (my $line = <$fh>) {
++ chomp($line);
+
+- my $expected = '\d+:\d+:\d+,\d+\s+\[\d+\]\s+<(\S+):(\d+)>: (.*?)$';
++ if ($ENV{TEST_VERBOSE}) {
++ print STDERR "# $line\n";
++ }
+
+- if ($line =~ /$expected/) {
+- my $trace_channel = $1;
+- my $trace_level = $2;
+- my $trace_msg = $3;
++ my $expected = '\[\d+\]\s+<(\S+):(\d+)>: (.*?)$';
+
+- next unless $trace_channel eq 'command';
++ if ($line =~ /$expected/) {
++ my $trace_channel = $1;
++ my $trace_level = $2;
++ my $trace_msg = $3;
+
+- my $expected = 'command';
+- $self->assert($expected eq $trace_channel,
+- test_msg("Expected '$expected', got '$trace_channel'"));
++ next unless $trace_channel eq 'command';
+
+- $expected = 7;
+- $self->assert($expected >= $trace_level,
+- test_msg("Expected >= $expected, got $trace_level"));
++ my $expected = 'command';
++ $self->assert($expected eq $trace_channel,
++ test_msg("Expected '$expected', got '$trace_channel'"));
+
+- $ok = 1;
+- last;
+- }
+- }
++ $expected = 7;
++ $self->assert($expected >= $trace_level,
++ test_msg("Expected >= $expected, got $trace_level"));
+
+- close($fh);
++ $ok = 1;
++ last;
++ }
++ }
+
+- $self->assert($ok, test_msg("Missing expected TraceLog messages"));
++ close($fh);
+
+- } else {
+- die("Can't read $trace_log: $!");
+- }
++ $self->assert($ok, test_msg("Missing expected TraceLog messages"));
+
+- if ($ex) {
+- die($ex);
++ } else {
++ die("Can't read $trace_log: $!");
++ }
++ };
++ if ($@) {
++ $ex = $@;
+ }
+
+- unlink($log_file);
++ test_cleanup($setup->{log_file}, $ex);
+ }
+
+ 1;
diff --git a/proftpd.conf b/proftpd.conf
index d96ebda..edb0f0c 100644
--- a/proftpd.conf
+++ b/proftpd.conf
@@ -114,6 +114,9 @@ UseSendfile off
LogFormat default "%h %l %u %t \"%r\" %s %b"
LogFormat auth "%v [%P] %h %t \"%r\" %s"
+# Don't log hostname or timestamps because systemd will do that for us
+LogOptions -Timestamp -Hostname +RoleBasedProcessLabels
+
# Enable basic controls via ftpdctl
# (http://www.proftpd.org/docs/modules/mod_ctrls.html)
ControlsEngine on
diff --git a/proftpd.spec b/proftpd.spec
index 34c8933..ed4ed1d 100644
--- a/proftpd.spec
+++ b/proftpd.spec
@@ -66,7 +66,7 @@
%undefine _strict_symbol_defs_build
%global prever rc3
-%global baserelease 2
+%global baserelease 3
%global mod_vroot_version 0.9.5
Summary: Flexible, stable and highly-configurable FTP server
@@ -93,6 +93,8 @@ Patch3: proftpd-1.3.4rc1-mod_vroot-test.patch
Patch4: proftpd-1.3.6-no-mod-wrap.patch
Patch5: proftpd-1.3.6-no-mod-geoip.patch
Patch6: https://github.com/proftpd/proftpd/commit/f8047a1e.patch
+Patch7: proftpd-1.3.7rc3-logoptions.patch
+Patch8: proftpd-1.3.7rc3-logging-not-systemd.patch
BuildRequires: coreutils
BuildRequires: gcc
@@ -305,16 +307,26 @@ mv contrib/README contrib/README.contrib
# LogFormat functionality still works
%patch6 -p1
+# Add options to vary logging format
+# https://bugzilla.redhat.com/show_bug.cgi?id=1808989
+# http://bugs.proftpd.org/show_bug.cgi?id=4185
+# https://github.com/proftpd/proftpd/issues/1002
+# https://github.com/proftpd/proftpd/pull/1009
+%patch7
+
# OpenSSL Cipher Profiles introduced in Fedora 21
# Elsewhere, we use the default of DEFAULT:!ADH:!EXPORT:!DES
%if (0%{?rhel} && 0%{?rhel} <= 7) || (0%{?fedora} && 0%{?fedora} <= 20)
sed -i -e '/^[[:space:]]*TLSCipherSuite[[:space:]]*PROFILE=SYSTEM$/d' mod_tls.conf
%endif
-# Tweak logrotate script for systemd compatibility (#802178)
%if %{use_systemd}
+# Tweak logrotate script for systemd compatibility (#802178)
sed -i -e '/killall/s/test.*/systemctl reload proftpd.service/' \
contrib/dist/rpm/proftpd.logrotate
+%else
+# Not using systemd, so we want hostname and timestamp in log messages
+%patch8
%endif
# Avoid docfile dependencies
@@ -590,6 +602,12 @@ fi
%{_mandir}/man1/ftpwho.1*
%changelog
+* Sat May 9 2020 Paul Howarth - 1.3.7-0.3.rc3
+- Avoid duplicate hostname and timestamps in syslog (#1808989)
+ http://bugs.proftpd.org/show_bug.cgi?id=4185
+ https://github.com/proftpd/proftpd/issues/1002
+ https://github.com/proftpd/proftpd/pull/1009
+
* Mon Apr 20 2020 Paul Howarth - 1.3.7-0.2.rc3
- Retain a memory pool after an aborted transfer so that the %%{transfer-status}
LogFormat functionality still works