From 9c8974ba6d93bcf76033c3e19dbf034d58cb4d50 Mon Sep 17 00:00:00 2001 From: Janne Blomqvist <janne.blomqvist@aalto.fi> Date: Thu, 25 Jul 2013 13:37:49 -0700 Subject: [PATCH] Make the timestamp format configurable in slurm.conf and slurmdbd.conf. --- auxdir/x_ac_rfc5424_time.m4 | 56 ------------------- configure.ac | 4 -- doc/man/man5/slurm.conf.5 | 12 +++++ doc/man/man5/slurmdbd.conf.5 | 12 +++++ slurm/slurm.h.in | 7 +++ src/common/log.c | 102 +++++++++++++++++++++++------------ src/common/log.h | 3 ++ src/common/read_config.c | 18 +++++++ src/common/xstring.c | 22 ++++---- src/common/xstring.h | 8 +-- src/slurmctld/controller.c | 3 ++ src/slurmctld/proc_req.c | 1 + src/slurmd/slurmd/slurmd.c | 2 + src/slurmd/slurmd/slurmd.h | 1 + src/slurmdbd/read_config.c | 19 +++++++ src/slurmdbd/read_config.h | 1 + src/slurmdbd/slurmdbd.c | 1 + 17 files changed, 161 insertions(+), 111 deletions(-) delete mode 100644 auxdir/x_ac_rfc5424_time.m4 diff --git a/auxdir/x_ac_rfc5424_time.m4 b/auxdir/x_ac_rfc5424_time.m4 deleted file mode 100644 index 4a31cafa4de..00000000000 --- a/auxdir/x_ac_rfc5424_time.m4 +++ /dev/null @@ -1,56 +0,0 @@ -##***************************************************************************** -# AUTHOR: -# Janne Blomqvist <janne.blomqvist@aalto.fi> -# -# SYNOPSIS: -# X_AC_RFC5424_TIME -# -# DESCRIPTION: -# Test for RFC 5424 compliant time support. -# Test for time stamp resolution to the millisecond (default) or second -##***************************************************************************** - -AC_DEFUN([X_AC_RFC5424_TIME], [ - AC_MSG_CHECKING([whether to enable RFC 5424 time format support]) - AC_ARG_ENABLE( - [rfc5424time], - AS_HELP_STRING(--enable-rfc5424time, enable RFC 5424 time format support), - [ case "$enableval" in - yes) x_ac_rfc5424time=yes ;; - no) x_ac_rfc5424time=no ;; - *) AC_MSG_RESULT([doh!]) - AC_MSG_ERROR([bad value "$enableval" for --enable-rfc5424time]) ;; - esac - ], - [x_ac_rfc5424time=no] - ) - - if test "$x_ac_rfc5424time" = yes; then - AC_MSG_RESULT([yes]) - AC_DEFINE(USE_RFC5424_TIME,,[define if using RFC 5424 time format]) - else - AC_MSG_RESULT([no]) - fi - - AC_MSG_CHECKING([log timestamps to millisecond resolution]) - AC_ARG_ENABLE( - [log-time-msec], - AS_HELP_STRING(--disable-log-time-msec, log timestamps to millisecond resolution), - [ case "$enableval" in - yes) x_ac_log_time_msec=yes ;; - no) x_ac_log_time_msec=no ;; - *) AC_MSG_RESULT([doh!]) - AC_MSG_ERROR([bad value "$enableval" for --disable-log-time-msec]) ;; - esac - ], - [x_ac_log_time_msec=yes] - ) - - if test "$x_ac_log_time_msec" = yes; then - AC_MSG_RESULT([yes]) - AC_DEFINE(LOG_TIME_MSEC,,[log timestamps to millisecond resolution]) - else - AC_MSG_RESULT([no]) - fi -]) - diff --git a/configure.ac b/configure.ac index de327a81ebc..92bf3585536 100644 --- a/configure.ac +++ b/configure.ac @@ -162,10 +162,6 @@ dnl dnl Check for PAM module support X_AC_PAM -dnl -dnl Check whether RFC 5424 time format should be used -X_AC_RFC5424_TIME - dnl dnl Check for ISO compliance X_AC_ISO diff --git a/doc/man/man5/slurm.conf.5 b/doc/man/man5/slurm.conf.5 index ed87657b534..a649a73b68e 100644 --- a/doc/man/man5/slurm.conf.5 +++ b/doc/man/man5/slurm.conf.5 @@ -987,6 +987,18 @@ required license specification is not available. SLURM does not prevent jobs from using licenses that are not explicitly listed in the job submission specification. +.TP +\fBLogTimeFormat\fR +Format of the timestamp in slurmctld and slurmd log files. Accepted +values are "iso8601", "iso8601_ms", "rfc5424", "rfc5424_ms", "clock", +and "short". The values ending in "_ms" differ from the ones without +in that fractional seconds with millisecond precision are printed. The +default value is "iso8601_ms". The "rfc5424" formats are the same as +the "iso8601" formats except that the timezone value is also +shown. The "clock" format shows a timestamp in microseconds retrieved +with the C standard clock() function. The "short" format is a short +date and time format. + .TP \fBMailProg\fR Fully qualified pathname to the program used to send email per user request. diff --git a/doc/man/man5/slurmdbd.conf.5 b/doc/man/man5/slurmdbd.conf.5 index cf30d5558b6..1088dc72e96 100644 --- a/doc/man/man5/slurmdbd.conf.5 +++ b/doc/man/man5/slurmdbd.conf.5 @@ -200,6 +200,18 @@ The default value is none (performs logging via syslog). See the section \fBLOGGING\fR in the slurm.conf man page if a pathname is specified. +.TP +\fBLogTimeFormat\fR +Format of the timestamp in slurmdbd log files. Accepted values are +"iso8601", "iso8601_ms", "rfc5424", "rfc5424_ms", "clock", and +"short". The values ending in "_ms" differ from the ones without in +that fractional seconds with millisecond precision are printed. The +default value is "iso8601_ms". The "rfc5424" formats are the same as +the "iso8601" formats except that the timezone value is also +shown. The "clock" format shows a timestamp in microseconds retrieved +with the C standard clock() function. The "short" format is a short +date and time format. + .TP \fBMessageTimeout\fR Time permitted for a round\-trip communication to complete diff --git a/slurm/slurm.h.in b/slurm/slurm.h.in index 4b81f7f6efa..9d867d6769d 100644 --- a/slurm/slurm.h.in +++ b/slurm/slurm.h.in @@ -1961,6 +1961,12 @@ typedef struct reservation_name_msg { #define HEALTH_CHECK_NODE_MIXED 0x0004 /* execute on partially allocated nodes */ #define HEALTH_CHECK_NODE_ANY 0xffff /* execute on all node states */ +#define LOG_FMT_ISO8601_MS 0 +#define LOG_FMT_ISO8601 1 +#define LOG_FMT_RFC5424_MS 2 +#define LOG_FMT_RFC5424 3 +#define LOG_FMT_CLOCK 4 +#define LOG_FMT_SHORT 5 typedef struct slurm_ctl_conf { time_t last_update; /* last update time of the build parameters */ @@ -2045,6 +2051,7 @@ typedef struct slurm_ctl_conf { char *launch_type; /* type of step launcher to use */ char *licenses; /* licenses available on this cluster */ char *licenses_used; /* licenses used on this cluster */ + uint16_t log_fmt; /* Log file timestamp format */ char *mail_prog; /* pathname of mail program */ uint16_t max_array_sz; /* Maximum job array size */ uint32_t max_job_cnt; /* maximum number of active jobs */ diff --git a/src/common/log.c b/src/common/log.c index 4c3250d58d1..9d224d8afe6 100644 --- a/src/common/log.c +++ b/src/common/log.c @@ -134,6 +134,7 @@ typedef struct { log_facility_t facility; log_options_t opt; unsigned initialized:1; + uint16_t fmt; /* Flag for specifying timestamp format */ uint32_t debug_flags; } log_t; @@ -201,25 +202,33 @@ size_t rfc2822_timestamp(char *s, size_t max) size_t log_timestamp(char *s, size_t max) { -#ifdef USE_RFC5424_TIME - size_t written = _make_timestamp(s, max, "%Y-%m-%dT%T%z"); - if (max >= 26 && written == 24) { - /* The strftime %z format creates timezone offsets of - * the form (+/-)hhmm, whereas the RFC 5424 format is - * (+/-)hh:mm. So shift the minutes one step back and - * insert the semicolon. */ - s[25] = '\0'; - s[24] = s[23]; - s[23] = s[22]; - s[22] = ':'; - return written + 1; + if (!log) + return _make_timestamp(s, max, "%Y-%m-%dT%T"); + switch (log->fmt) { + case LOG_FMT_RFC5424_MS: + case LOG_FMT_RFC5424: + { + size_t written = _make_timestamp(s, max, "%Y-%m-%dT%T%z"); + if (max >= 26 && written == 24) { + /* The strftime %z format creates timezone offsets of + * the form (+/-)hhmm, whereas the RFC 5424 format is + * (+/-)hh:mm. So shift the minutes one step back and + * insert the semicolon. */ + s[25] = '\0'; + s[24] = s[23]; + s[23] = s[22]; + s[22] = ':'; + return written + 1; + } + return written; + } + case LOG_FMT_SHORT: + return _make_timestamp(s, max, "%b %d %T"); + break; + default: + return _make_timestamp(s, max, "%Y-%m-%dT%T"); + break; } - return written; -#elif defined USE_ISO_8601 - return _make_timestamp(s, max, "%Y-%m-%dT%T"); -#else - return _make_timestamp(s, max, "%b %d %T"); -#endif } /* check to see if a file is writeable, @@ -644,6 +653,19 @@ void log_oom(const char *file, int line, const char *func) } } + +/* Set the timestamp format flag */ +void log_set_timefmt(unsigned fmtflag) +{ + if (log) { + slurm_mutex_lock(&log_lock); + log->fmt = fmtflag; + slurm_mutex_unlock(&log_lock); + } else + fprintf(stderr, "Slurm log not initialized\n"); +} + + /* return a heap allocated string formed from fmt and ap arglist * returned string is allocated with xmalloc, so must free with xfree. * @@ -698,24 +720,34 @@ static char *vxstrfmt(const char *fmt, va_list ap) case 'T': /* "%T" => "dd, Mon yyyy hh:mm:ss off" */ xstrftimecat(buf, "%a, %d %b %Y %H:%M:%S %z"); break; -#if defined USE_USEC_CLOCK - case 'M': /* "%M" => "usec" */ - snprintf(tmp, sizeof(tmp), "%ld", clock()); - xstrcat(buf, tmp); - break; -#elif defined USE_RFC5424_TIME - case 'M': /* "%M" => "yyyy-mm-ddThh:mm:ss.fff(+/-)hh:mm" */ - xrfc5424timecat(buf); - break; -#elif defined USE_ISO_8601 - case 'M': /* "%M" => "yyyy-mm-ddThh:mm:ss.fff" */ - xiso8601timecat(buf); - break; -#else - case 'M': /* "%M" => "Mon DD hh:mm:ss" */ - xstrftimecat(buf, "%b %d %T"); + case 'M': + if (!log) + xiso8601timecat(buf, true); + else { + switch (log->fmt) { + case LOG_FMT_ISO8601_MS: /* "%M" => "yyyy-mm-ddThh:mm:ss.fff" */ + xiso8601timecat(buf, true); + break; + case LOG_FMT_ISO8601: /* "%M" => "yyyy-mm-ddThh:mm:ss.fff" */ + xiso8601timecat(buf, false); + break; + case LOG_FMT_RFC5424_MS: /* "%M" => "yyyy-mm-ddThh:mm:ss.fff(+/-)hh:mm" */ + xrfc5424timecat(buf, true); + break; + case LOG_FMT_RFC5424: /* "%M" => "yyyy-mm-ddThh:mm:ss.fff(+/-)hh:mm" */ + xrfc5424timecat(buf, false); + break; + case LOG_FMT_CLOCK: + /* "%M" => "usec" */ + snprintf(tmp, sizeof(tmp), "%ld", clock()); + xstrcat(buf, tmp); + break; + case LOG_FMT_SHORT: /* "%M" => "Mon DD hh:mm:ss" */ + xstrftimecat(buf, "%b %d %T"); + break; + } + } break; -#endif case 's': /* "%s" => append string */ /* we deal with this case for efficiency */ if (unprocessed == 0) diff --git a/src/common/log.h b/src/common/log.h index 753dd23bd0a..d8a96fd2f9d 100644 --- a/src/common/log.h +++ b/src/common/log.h @@ -217,6 +217,9 @@ void log_fatal(const char *file, int line, const char *msg, const char *err_str) /* Log out of memory without message buffering */ void log_oom(const char *file, int line, const char *func); +/* Set the log timestamp format */ +void log_set_timefmt(unsigned); + /* * Buffered log functions: * diff --git a/src/common/read_config.c b/src/common/read_config.c index 815f6f56702..fda9355b405 100644 --- a/src/common/read_config.c +++ b/src/common/read_config.c @@ -225,6 +225,7 @@ s_p_options_t slurm_conf_options[] = { {"KillWait", S_P_UINT16}, {"LaunchType", S_P_STRING}, {"Licenses", S_P_STRING}, + {"LogTimeFormat", S_P_STRING}, {"MailProg", S_P_STRING}, {"MaxArraySize", S_P_UINT16}, {"MaxJobCount", S_P_UINT32}, @@ -2952,6 +2953,23 @@ _validate_and_set_defaults(slurm_ctl_conf_t *conf, s_p_hashtbl_t *hashtbl) s_p_get_string(&conf->licenses, "Licenses", hashtbl); + if (s_p_get_string(&temp_str, "LogTimeFormat", hashtbl)) { + if (slurm_strcasestr(temp_str, "iso8601_ms")) + conf->log_fmt = LOG_FMT_ISO8601_MS; + else if (slurm_strcasestr(temp_str, "iso8601")) + conf->log_fmt = LOG_FMT_ISO8601; + else if (slurm_strcasestr(temp_str, "rfc5424_ms")) + conf->log_fmt = LOG_FMT_RFC5424_MS; + else if (slurm_strcasestr(temp_str, "rfc5424")) + conf->log_fmt = LOG_FMT_RFC5424; + else if (slurm_strcasestr(temp_str, "clock")) + conf->log_fmt = LOG_FMT_CLOCK; + else if (slurm_strcasestr(temp_str, "short")) + conf->log_fmt = LOG_FMT_SHORT; + xfree(temp_str); + } else + conf->log_fmt = LOG_FMT_ISO8601_MS; + if (!s_p_get_string(&conf->mail_prog, "MailProg", hashtbl)) conf->mail_prog = xstrdup(DEFAULT_MAIL_PROG); diff --git a/src/common/xstring.c b/src/common/xstring.c index c9f680b68e0..5ec5582d749 100644 --- a/src/common/xstring.c +++ b/src/common/xstring.c @@ -220,7 +220,7 @@ void _xstrftimecat(char **buf, const char *fmt) /* * Append a ISO 8601 formatted timestamp to buffer buf, expand as needed */ -void _xiso8601timecat(char **buf) +void _xiso8601timecat(char **buf, bool msec) { char p[64] = ""; struct timeval tv; @@ -235,18 +235,17 @@ void _xiso8601timecat(char **buf) if (strftime(p, sizeof(p), "%Y-%m-%dT%T", &tm) == 0) fprintf(stderr, "strftime() returned 0\n"); -#if defined LOG_TIME_MSEC /* Add millisecond data */ - _xstrfmtcat(buf, "%s.%3.3d", p, (int)(tv.tv_usec / 1000)); -#else - _xstrfmtcat(buf, "%s", p); -#endif + if (msec) + _xstrfmtcat(buf, "%s.%3.3d", p, (int)(tv.tv_usec / 1000)); + else + _xstrfmtcat(buf, "%s", p); } /* * Append a RFC 5424 formatted timestamp to buffer buf, expand as needed * */ -void _xrfc5424timecat(char **buf) +void _xrfc5424timecat(char **buf, bool msec) { char p[64] = ""; char z[12] = ""; @@ -272,11 +271,10 @@ void _xrfc5424timecat(char **buf) z[4] = z[3]; z[3] = ':'; -#if defined LOG_TIME_MSEC /* Add millisecond data */ - _xstrfmtcat(buf, "%s.%3.3d%s", p, (int)(tv.tv_usec / 1000), z); -#else - _xstrfmtcat(buf, "%s%s", p, z); -#endif + if (msec) + _xstrfmtcat(buf, "%s.%3.3d%s", p, (int)(tv.tv_usec / 1000), z); + else + _xstrfmtcat(buf, "%s%s", p, z); } /* diff --git a/src/common/xstring.h b/src/common/xstring.h index 06dc7423617..85811a8d7e6 100644 --- a/src/common/xstring.h +++ b/src/common/xstring.h @@ -47,8 +47,8 @@ #define xstrcatchar(__p, __c) _xstrcatchar(&(__p), __c) #define xslurm_strerrorcat(__p) _xslurm_strerrorcat(&(__p)) #define xstrftimecat(__p, __fmt) _xstrftimecat(&(__p), __fmt) -#define xiso8601timecat(__p) _xiso8601timecat(&(__p)) -#define xrfc5424timecat(__p) _xrfc5424timecat(&(__p)) +#define xiso8601timecat(__p, __msec) _xiso8601timecat(&(__p), __msec) +#define xrfc5424timecat(__p, __msec) _xrfc5424timecat(&(__p), __msec) #define xstrfmtcat(__p, __fmt, args...) _xstrfmtcat(&(__p), __fmt, ## args) #define xmemcat(__p, __s, __e) _xmemcat(&(__p), __s, __e) #define xstrsubstitute(__p, __pat, __rep) _xstrsubstitute(&(__p), __pat, __rep) @@ -93,12 +93,12 @@ void _xstrftimecat(char **str, const char *fmt); /* ** Concatenate a ISO 8601 timestamp onto str. */ -void _xiso8601timecat(char **str); +void _xiso8601timecat(char **str, bool); /* ** Concatenate a RFC 5424 timestamp onto str. */ -void _xrfc5424timecat(char **str); +void _xrfc5424timecat(char **str, bool); /* ** concatenate printf-style formatted string onto str diff --git a/src/slurmctld/controller.c b/src/slurmctld/controller.c index 1218167a351..d3b283c18b3 100644 --- a/src/slurmctld/controller.c +++ b/src/slurmctld/controller.c @@ -262,6 +262,7 @@ int main(int argc, char *argv[]) slurmctld_config.daemonize = 1; if (daemon(1, 1)) error("daemon(): %m"); + log_set_timefmt(slurmctld_conf.log_fmt); log_alter(log_opts, LOG_DAEMON, slurmctld_conf.slurmctld_logfile); sched_log_alter(sched_log_opts, LOG_DAEMON, @@ -1974,6 +1975,8 @@ void update_logging(void) log_alter(log_opts, SYSLOG_FACILITY_DAEMON, slurmctld_conf.slurmctld_logfile); + log_set_timefmt(slurmctld_conf.log_fmt); + /* * SchedLogLevel restore */ diff --git a/src/slurmctld/proc_req.c b/src/slurmctld/proc_req.c index c3fa7ce7946..37e212652a5 100644 --- a/src/slurmctld/proc_req.c +++ b/src/slurmctld/proc_req.c @@ -590,6 +590,7 @@ void _fill_ctld_conf(slurm_ctl_conf_t * conf_ptr) conf_ptr->launch_type = xstrdup(conf->launch_type); conf_ptr->licenses = xstrdup(conf->licenses); conf_ptr->licenses_used = get_licenses_used(); + conf_ptr->log_fmt = conf->log_fmt; conf_ptr->mail_prog = xstrdup(conf->mail_prog); conf_ptr->max_array_sz = conf->max_array_sz; diff --git a/src/slurmd/slurmd/slurmd.c b/src/slurmd/slurmd/slurmd.c index bac4f18f8d7..0f44ab6fc1d 100644 --- a/src/slurmd/slurmd/slurmd.c +++ b/src/slurmd/slurmd/slurmd.c @@ -1774,6 +1774,7 @@ static void _update_logging(void) if ( (conf->debug_level == LOG_LEVEL_INFO) && (cf->slurmd_debug != (uint16_t) NO_VAL) ) conf->debug_level = cf->slurmd_debug; + conf->log_fmt = cf->log_fmt; slurm_conf_unlock(); o->stderr_level = conf->debug_level; @@ -1795,6 +1796,7 @@ static void _update_logging(void) o->syslog_level = LOG_LEVEL_QUIET; log_alter(conf->log_opts, SYSLOG_FACILITY_DAEMON, conf->logfile); + log_set_timefmt(conf->log_fmt); } /* Reset slurmd nice value */ diff --git a/src/slurmd/slurmd/slurmd.h b/src/slurmd/slurmd/slurmd.h index bb73f876208..a5418413c74 100644 --- a/src/slurmd/slurmd/slurmd.h +++ b/src/slurmd/slurmd/slurmd.h @@ -122,6 +122,7 @@ typedef struct slurmd_config { slurm_fd_t lfd; /* slurmd listen file descriptor */ pid_t pid; /* server pid */ log_options_t log_opts; /* current logging options */ + uint16_t log_fmt; /* Log file timestamp format flag */ int debug_level; /* logging detail level */ uint32_t debug_flags; /* DebugFlags configured */ int daemonize:1; /* daemonize flag */ diff --git a/src/slurmdbd/read_config.c b/src/slurmdbd/read_config.c index 982f284b79c..4ede629e5c3 100644 --- a/src/slurmdbd/read_config.c +++ b/src/slurmdbd/read_config.c @@ -144,6 +144,7 @@ extern int read_slurmdbd_conf(void) {"DefaultQOS", S_P_STRING}, {"JobPurge", S_P_UINT32}, {"LogFile", S_P_STRING}, + {"LogTimeFormat", S_P_STRING}, {"MessageTimeout", S_P_UINT16}, {"PidFile", S_P_STRING}, {"PluginDir", S_P_STRING}, @@ -236,6 +237,24 @@ extern int read_slurmdbd_conf(void) } s_p_get_string(&slurmdbd_conf->log_file, "LogFile", tbl); + + if (s_p_get_string(&temp_str, "LogTimeFormat", tbl)) { + if (slurm_strcasestr(temp_str, "iso8601_ms")) + slurmdbd_conf->log_fmt = LOG_FMT_ISO8601_MS; + else if (slurm_strcasestr(temp_str, "iso8601")) + slurmdbd_conf->log_fmt = LOG_FMT_ISO8601; + else if (slurm_strcasestr(temp_str, "rfc5424_ms")) + slurmdbd_conf->log_fmt = LOG_FMT_RFC5424_MS; + else if (slurm_strcasestr(temp_str, "rfc5424")) + slurmdbd_conf->log_fmt = LOG_FMT_RFC5424; + else if (slurm_strcasestr(temp_str, "clock")) + slurmdbd_conf->log_fmt = LOG_FMT_CLOCK; + else if (slurm_strcasestr(temp_str, "short")) + slurmdbd_conf->log_fmt = LOG_FMT_SHORT; + xfree(temp_str); + } else + slurmdbd_conf->log_fmt = LOG_FMT_ISO8601_MS; + if (!s_p_get_uint16(&slurmdbd_conf->msg_timeout, "MessageTimeout", tbl)) slurmdbd_conf->msg_timeout = DEFAULT_MSG_TIMEOUT; diff --git a/src/slurmdbd/read_config.h b/src/slurmdbd/read_config.h index eacba760169..12714d03aed 100644 --- a/src/slurmdbd/read_config.h +++ b/src/slurmdbd/read_config.h @@ -82,6 +82,7 @@ typedef struct slurm_dbd_conf { char * default_qos; /* default qos setting when * adding clusters */ char * log_file; /* Log file */ + uint16_t log_fmt; /* Log file timestamt format */ uint16_t msg_timeout; /* message timeout */ char * pid_file; /* where to store current PID */ char * plugindir; /* dir to look for plugins */ diff --git a/src/slurmdbd/slurmdbd.c b/src/slurmdbd/slurmdbd.c index 2002abe029d..92a4f82d31b 100644 --- a/src/slurmdbd/slurmdbd.c +++ b/src/slurmdbd/slurmdbd.c @@ -385,6 +385,7 @@ static void _update_logging(bool startup) } log_alter(log_opts, SYSLOG_FACILITY_DAEMON, slurmdbd_conf->log_file); + log_set_timefmt(slurmdbd_conf->log_fmt); if (startup && slurmdbd_conf->log_file) { int rc; gid_t slurm_user_gid; -- GitLab