From: Evan Hunt Date: Thu, 9 Mar 2017 07:20:40 +0000 (-0800) Subject: [master] timestamp suffixes for log files X-Git-Tag: v9.12.0a1~418 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=612b2e2c0df9e5c9efbb8969c49d6fcb588b861e;p=thirdparty%2Fbind9.git [master] timestamp suffixes for log files 4579. [func] Logging channels and dnstap output files can now be configured with a "suffix" option, set to either "increment" or "timestamp", indicating whether to use incrementing numbers or timestamps as the file suffix when rolling over a log file. [RT #42838] --- diff --git a/CHANGES b/CHANGES index edc11d38f36..a6e60e0cffc 100644 --- a/CHANGES +++ b/CHANGES @@ -1,3 +1,10 @@ +4579. [func] Logging channels and dnstap output files can now + be configured with a "suffix" option, set to + either "increment" or "timestamp", indicating + whether to use incrementing numbers or timestamps + as the file suffix when rolling over a log file. + [RT #42838] + 4578. [security] Some chaining (CNAME or DNAME) responses to upstream queries could trigger assertion failures. (CVE-2017-3137) [RT #44734] diff --git a/bin/named/logconf.c b/bin/named/logconf.c index 02d4dec39fb..2f52affcb81 100644 --- a/bin/named/logconf.c +++ b/bin/named/logconf.c @@ -132,7 +132,10 @@ channel_fromconf(const cfg_obj_t *channel, isc_logconfig_t *logconfig) { const cfg_obj_t *sizeobj = cfg_tuple_get(fileobj, "size"); const cfg_obj_t *versionsobj = cfg_tuple_get(fileobj, "versions"); + const cfg_obj_t *suffixobj = + cfg_tuple_get(fileobj, "suffix"); isc_int32_t versions = ISC_LOG_ROLLNEVER; + isc_log_rollsuffix_t suffix = isc_log_rollsuffix_increment; isc_offset_t size = 0; isc_uint64_t maxoffset; @@ -155,16 +158,21 @@ channel_fromconf(const cfg_obj_t *channel, isc_logconfig_t *logconfig) { if (versionsobj != NULL && cfg_obj_isuint32(versionsobj)) versions = cfg_obj_asuint32(versionsobj); - if (versionsobj != NULL && cfg_obj_isstring(versionsobj) && + else if (versionsobj != NULL && cfg_obj_isstring(versionsobj) && strcasecmp(cfg_obj_asstring(versionsobj), "unlimited") == 0) versions = ISC_LOG_ROLLINFINITE; if (sizeobj != NULL && cfg_obj_isuint64(sizeobj) && cfg_obj_asuint64(sizeobj) < maxoffset) size = (isc_offset_t)cfg_obj_asuint64(sizeobj); + if (suffixobj != NULL && cfg_obj_isstring(suffixobj) && + strcasecmp(cfg_obj_asstring(suffixobj), "timestamp") == 0) + suffix = isc_log_rollsuffix_timestamp; + dest.file.stream = NULL; dest.file.name = cfg_obj_asstring(pathobj); dest.file.versions = versions; + dest.file.suffix = suffix; dest.file.maximum_size = size; } else if (syslogobj != NULL) { int facility = LOG_DAEMON; @@ -182,6 +190,7 @@ channel_fromconf(const cfg_obj_t *channel, isc_logconfig_t *logconfig) { dest.file.stream = stderr; dest.file.name = NULL; dest.file.versions = ISC_LOG_ROLLNEVER; + dest.file.suffix = isc_log_rollsuffix_increment; dest.file.maximum_size = 0; } diff --git a/bin/named/server.c b/bin/named/server.c index b512b5ddfb7..d9f779a3d1c 100644 --- a/bin/named/server.c +++ b/bin/named/server.c @@ -3090,6 +3090,8 @@ configure_dnstap(const cfg_obj_t **maps, dns_view_t *view) { dns_dtmode_t dmode; isc_uint64_t max_size = 0; isc_uint32_t rolls = 0; + isc_log_rollsuffix_t suffix = isc_log_rollsuffix_increment; + obj = NULL; CHECKM(ns_config_get(maps, "dnstap-output", &obj), "'dnstap-output' must be set if 'dnstap' is set"); @@ -3126,12 +3128,15 @@ configure_dnstap(const cfg_obj_t **maps, dns_view_t *view) { obj2 = cfg_tuple_get(obj, "versions"); if (obj2 != NULL && cfg_obj_isuint32(obj2)) { rolls = cfg_obj_asuint32(obj2); - } else if (obj2 != NULL && cfg_obj_isstring(obj2) && - strcasecmp(cfg_obj_asstring(obj2), "unlimited") == 0) - { - rolls = ISC_LOG_ROLLINFINITE; } else { - rolls = ISC_LOG_ROLLNEVER; + rolls = ISC_LOG_ROLLINFINITE; + } + + obj2 = cfg_tuple_get(obj, "suffix"); + if (obj2 != NULL && cfg_obj_isstring(obj2) && + strcasecmp(cfg_obj_asstring(obj2), "timestamp") == 0) + { + suffix = isc_log_rollsuffix_timestamp; } fopt = fstrm_iothr_options_init(); @@ -3202,7 +3207,8 @@ configure_dnstap(const cfg_obj_t **maps, dns_view_t *view) { &fopt, &ns_g_server->dtenv), "unable to create dnstap environment"); - CHECKM(dns_dt_setupfile(ns_g_server->dtenv, max_size, rolls), + CHECKM(dns_dt_setupfile(ns_g_server->dtenv, + max_size, rolls, suffix), "unable to set up dnstap logfile"); } @@ -13730,9 +13736,12 @@ ns_server_dnstap(ns_server_t *server, isc_lex_t *lex, isc_buffer_t **text) { n = sscanf(ptr, "%u", &backups); if (n != 1U) return (ISC_R_BADNUMBER); + } else { + backups = ISC_LOG_ROLLINFINITE; } - } else + } else { return (DNS_R_SYNTAX); + } result = isc_task_beginexclusive(server->task); RUNTIME_CHECK(result == ISC_R_SUCCESS); diff --git a/bin/tests/system/dnstap/good-size-unlimited.conf b/bin/tests/system/dnstap/good-size-unlimited.conf index 7b04fbb347b..f520716dc8a 100644 --- a/bin/tests/system/dnstap/good-size-unlimited.conf +++ b/bin/tests/system/dnstap/good-size-unlimited.conf @@ -7,5 +7,6 @@ */ options { - dnstap-output file "/tmp/dnstap.log" size unlimited versions unlimited; + dnstap-output file "/tmp/dnstap.log" + size unlimited versions unlimited suffix increment; }; diff --git a/bin/tests/system/dnstap/good-size-version.conf b/bin/tests/system/dnstap/good-size-version.conf index 0a4573d9502..46022b73169 100644 --- a/bin/tests/system/dnstap/good-size-version.conf +++ b/bin/tests/system/dnstap/good-size-version.conf @@ -7,5 +7,6 @@ */ options { - dnstap-output file "/tmp/dnstap.log" size 10k versions 3; + dnstap-output file "/tmp/dnstap.log" + size 10k versions 3 suffix timestamp; }; diff --git a/bin/tests/system/logfileconfig/clean.sh b/bin/tests/system/logfileconfig/clean.sh index aa743c83ad3..98da66c030f 100644 --- a/bin/tests/system/logfileconfig/clean.sh +++ b/bin/tests/system/logfileconfig/clean.sh @@ -23,5 +23,7 @@ rm -f ns1/rndc.out.test* rm -f ns1/dig.out.test* rm -f ns1/named_vers rm -f ns1/named_vers.* +rm -f ns1/named_ts +rm -f ns1/named_ts.* rm -f ns1/named_unlimited rm -f ns1/named_unlimited.* diff --git a/bin/tests/system/logfileconfig/ns1/named.tsconf b/bin/tests/system/logfileconfig/ns1/named.tsconf new file mode 100644 index 00000000000..877de56911c --- /dev/null +++ b/bin/tests/system/logfileconfig/ns1/named.tsconf @@ -0,0 +1,56 @@ +/* + * Copyright (C) 2016 Internet Systems Consortium, Inc. ("ISC") + * + * This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at http://mozilla.org/MPL/2.0/. + */ + +options { + query-source address 10.53.0.1; + notify-source 10.53.0.1; + transfer-source 10.53.0.1; + port 5300; + pid-file "named.pid"; + listen-on port 5300 { + 10.53.0.1; + }; + listen-on-v6 { none; }; + recursion no; + notify yes; +}; + +logging { + channel default_log { + buffered no; + file "named_ts" versions 10 size 1000 suffix timestamp; # small size + severity debug 100; + print-time yes; + }; + category default { default_log; default_debug; }; + category lame-servers { null; }; + + channel query_log { + file "query_log"; + print-time yes; + buffered yes; + }; + category queries { query_log; }; +}; + +controls { + inet 127.0.0.1 port 9593 allow { + 127.0.0.1/32; ::1/128; } + keys { "rndc-key"; }; +}; + +key "rndc-key" { + algorithm hmac-sha256; + secret "Am9vCg=="; +}; + + +zone "." { + type master; + file "root.db"; +}; diff --git a/bin/tests/system/logfileconfig/tests.sh b/bin/tests/system/logfileconfig/tests.sh index 85ad115408b..298bce1dafe 100644 --- a/bin/tests/system/logfileconfig/tests.sh +++ b/bin/tests/system/logfileconfig/tests.sh @@ -19,6 +19,7 @@ PLAINCONF="${THISDIR}/${CONFDIR}/named.plainconf" ISOCONF="${THISDIR}/${CONFDIR}/named.iso8601" ISOCONFUTC="${THISDIR}/${CONFDIR}/named.iso8601-utc" VERSCONF="${THISDIR}/${CONFDIR}/named.versconf" +TSCONF="${THISDIR}/${CONFDIR}/named.tsconf" UNLIMITEDCONF="${THISDIR}/${CONFDIR}/named.unlimited" PLAINFILE="named_log" DIRFILE="named_dir" @@ -28,6 +29,7 @@ DLFILE="named_deflog" ISOFILE="named_iso8601" ISOUTCFILE="named_iso8601_utc" VERSFILE="named_vers" +TSFILE="named_ts" UNLIMITEDFILE="named_unlimited" PIDFILE="${THISDIR}/${CONFDIR}/named.pid" myRNDC="$RNDC -c ${THISDIR}/${CONFDIR}/rndc.conf" @@ -335,6 +337,32 @@ then status=`expr $status + 1` fi +n=`expr $n + 1` +echo "I: testing timestamped versions ($n)" +cp $TSCONF named.conf +# a seconds since epoch version number +touch $TSFILE.2015010112000012 +t1=`$PERL -e 'print time()."\n";'` +$myRNDC reconfig > rndc.out.test$n 2>&1 +$DIG version.bind txt ch @10.53.0.1 -p 5300 > dig.out.test$n +t2=`$PERL -e 'print time()."\n";'` +t=`expr ${t2:-0} - ${t1:-0}` +if test ${t:-1000} -gt 5 +then + echo "I: testing timestamped versions failed cleanup of old entries took too long ($t secs)" + status=`expr $status + 1` +fi +if ! grep "status: NOERROR" dig.out.test$n > /dev/null +then + echo "I: testing timestamped versions failed DiG lookup failed" + status=`expr $status + 1` +fi +if test -f $TSFILE.1480039317 +then + echo "I: testing timestamped versions failed $TSFILE.1480039317 not removed" + status=`expr $status + 1` +fi + n=`expr $n + 1` echo "I: testing unlimited versions ($n)" cp $UNLIMITEDCONF named.conf diff --git a/doc/arm/Bv9ARM-book.xml b/doc/arm/Bv9ARM-book.xml index ca1b17e3397..dbf0e86f554 100644 --- a/doc/arm/Bv9ARM-book.xml +++ b/doc/arm/Bv9ARM-book.xml @@ -3638,7 +3638,8 @@ $ORIGIN 0.0.0.0.0.0.0.0.8.b.d.0.1.0.0.2.ip6.arpa. [ channel channel_name { ( ( file path_name [ versions ( number | ) ] - [ size size_spec ] ) + [ size size_spec ] + [ suffix ( | ) ) | syslog syslog_facility | stderr | null ) ; @@ -3733,61 +3734,68 @@ $ORIGIN 0.0.0.0.0.0.0.0.8.b.d.0.1.0.0.2.ip6.arpa. The file destination clause directs - the channel - to a disk file. It can include limitations - both on how large the file is allowed to become, and how many - versions - of the file will be saved each time the file is opened. - - - - If you use the versions log file - option, then - named will retain that many backup - versions of the file by - renaming them when opening. For example, if you choose to keep - three old versions - of the file lamers.log, then just - before it is opened - lamers.log.1 is renamed to - lamers.log.2, lamers.log.0 is renamed - to lamers.log.1, and lamers.log is - renamed to lamers.log.0. - You can say versions unlimited to - not limit - the number of versions. - If a size option is associated with - the log file, - then renaming is only done when the file being opened exceeds the - indicated size. No backup versions are kept by default; any - existing - log file is simply appended. - - - - The size option for files is used - to limit log - growth. If the file ever exceeds the size, then named will - stop writing to the file unless it has a versions option - associated with it. If backup versions are kept, the files are - rolled as - described above and a new one begun. If there is no + the channel to a disk file. It can include additional + arguments to specify how large the file is allowed to + become before it is rolled to a backup file + (size), how many backup versions of + the file will be saved each time this happens + (versions), and the format to use + for naming backup versions (suffix). + + + + The size option is used to limit + log file growth. If the file ever exceeds the specified + size, then named will stop writing to the + file unless it has a versions option + associated with it. If backup versions are kept, the files + are rolled as described below. If there is no versions option, no more data will - be written to the log - until some out-of-band mechanism removes or truncates the log to - less than the - maximum size. The default behavior is not to limit the size of - the - file. - - - - Example usage of the size and - versions options: + be written to the log until some out-of-band mechanism + removes or truncates the log to less than the maximum size. + The default behavior is not to limit the size of the file. + + + File rolling only occurs when the file exceeds the size + specified with the size option. No + backup versions are kept by default; any existing + log file is simply appended. The + versions option specifies + how many backup versions of the file should be kept. + If set to unlimited, there is no limit. + + + The suffix option can be set to + either increment or + timestamp. If set to + timestamp, then when a log file is + rolled, it is saved with the current timestamp as a + file suffix. If set to increment, + then backup files are saved with incrementing numbers + as suffixes; older files are renamed when rolling. + For example, if versions + is set to 3 and suffix to + increment, then when + filename.log reaches the size + specified by size, + filename.log.1 is renamed to + filename.log.2, + filename.log.0 is renamed + to filename.log.1, + and filename.log is + renamed to filename.log.0, + whereupon a new filename.log is + opened. + + + + Example usage of the size, + versions, and suffix + options: channel an_example_channel { - file "example.log" versions 3 size 20m; + file "example.log" versions 3 size 20m suffix increment; print-time yes; print-category yes; }; @@ -5004,16 +5012,20 @@ badresp:1,adberr:0,findfail:0,valfail:0] If the first argument is file, then - two additional options can be added: + up to three additional options can be added: size indicates the size to which a dnstap log file can grow before being - rolled to a new file, and versions - specifies the number of rolled log files to retain. These - are similar to the size and - versions options in a - logging channel. The default - is to allow dnstap log files to grow to - any size without rolling. + rolled to a new file; versions + specifies the number of rolled log files to retain; and + suffix indicates whether to retain + rolled log files with an incrementing counter as the + suffix (increment) or with the + current timestamp (timestamp). + These are similar to the size, + versions, and suffix + options in a logging channel. + The default is to allow dnstap log + files to grow to any size without rolling. dnstap-output can only be set globally diff --git a/doc/arm/notes.xml b/doc/arm/notes.xml index 84b70b195ec..0e4109d1462 100644 --- a/doc/arm/notes.xml +++ b/doc/arm/notes.xml @@ -154,7 +154,7 @@ dnstap logfiles can now be configured to automatically roll when they reach a specified size. If dnstap-output is configured with mode - file, then it can take optional + file, then it can take optional size and versions key-value arguments to set the logfile rolling parameters. (These have the same semantics as the corresponding @@ -162,6 +162,19 @@ [RT #44502] + + + Logging channels and dnstap-output files can + now be configured with a suffix option, + set to either increment or + timestamp, indicating whether log files + should be given incrementing suffixes when they roll + over (e.g., logfile.0, + .1, .2, etc) + or suffixes indicating the time of the roll. The default + is increment. [RT #42838] + + dig +ednsopt now accepts the names diff --git a/doc/misc/options b/doc/misc/options index 68dd47ba0f7..a2107304143 100644 --- a/doc/misc/options +++ b/doc/misc/options @@ -33,8 +33,8 @@ logging { category { ; ... }; // may occur multiple times channel { buffered ; - file [ versions ( "unlimited" | ) - ] [ size ]; + file [ versions ( unlimited | ) ] + [ size ] [ suffix ( increment | timestamp ) ]; null; print-category ; print-severity ; @@ -155,7 +155,8 @@ options { hostname ); // not configured dnstap-output ( file | unix ) [ size ( unlimited | ) ] [ versions ( - unlimited | ) ]; // not configured + unlimited | ) ] [ suffix ( increment + | timestamp ) ]; // not configured dnstap-version ( | none ); // not configured dscp ; dual-stack-servers [ port ] { ( [ port diff --git a/lib/bind9/check.c b/lib/bind9/check.c index 8b4ef543404..ab5f6ae3d66 100644 --- a/lib/bind9/check.c +++ b/lib/bind9/check.c @@ -1476,6 +1476,16 @@ check_options(const cfg_obj_t *options, isc_log_t *logctx, isc_mem_t *mctx, "cannot be set with mode unix"); return (ISC_R_FAILURE); } + + obj2 = cfg_tuple_get(obj, "suffix"); + if (obj2 != NULL && !cfg_obj_isvoid(obj2) && + dmode == dns_dtmode_unix) + { + cfg_obj_log(obj, logctx, ISC_LOG_ERROR, + "dnstap-output suffix " + "cannot be set with mode unix"); + return (ISC_R_FAILURE); + } } #endif diff --git a/lib/dns/dnstap.c b/lib/dns/dnstap.c index e8b4564f64f..82148f6159a 100644 --- a/lib/dns/dnstap.c +++ b/lib/dns/dnstap.c @@ -50,6 +50,7 @@ #include #include +#include #include #include #include @@ -104,8 +105,9 @@ struct dns_dtenv { isc_region_t version; char *path; dns_dtmode_t mode; - isc_uint64_t max_size; - isc_uint32_t rolls; + isc_offset_t max_size; + int rolls; + isc_log_rollsuffix_t suffix; isc_stats_t *stats; }; @@ -185,7 +187,7 @@ dns_dt_create(isc_mem_t *mctx, dns_dtmode_t mode, const char *path, REQUIRE(path != NULL); REQUIRE(envp != NULL && *envp == NULL); - REQUIRE(foptp!= NULL && *foptp != NULL); + REQUIRE(foptp != NULL && *foptp != NULL); isc_log_write(dns_lctx, DNS_LOGCATEGORY_DNSTAP, DNS_LOGMODULE_DNSTAP, ISC_LOG_INFO, @@ -244,7 +246,7 @@ dns_dt_create(isc_mem_t *mctx, dns_dtmode_t mode, const char *path, } env->mode = mode; env->max_size = 0; - env->rolls = ISC_LOG_ROLLNEVER; + env->rolls = ISC_LOG_ROLLINFINITE; env->fopt = *foptp; *foptp = NULL; @@ -279,17 +281,28 @@ dns_dt_create(isc_mem_t *mctx, dns_dtmode_t mode, const char *path, } isc_result_t -dns_dt_setupfile(dns_dtenv_t *env, isc_uint64_t max_size, int rolls) { +dns_dt_setupfile(dns_dtenv_t *env, isc_uint64_t max_size, int rolls, + isc_log_rollsuffix_t suffix) +{ REQUIRE(VALID_DTENV(env)); - if (max_size != 0 && rolls != ISC_LOG_ROLLNEVER && - env->mode != dns_dtmode_file) - { - return (ISC_R_INVALIDFILE); + /* + * If we're using unix domain socket mode, then any + * change from the default values is invalid. + */ + if (env->mode == dns_dtmode_unix) { + if (max_size == 0 && rolls == ISC_LOG_ROLLINFINITE && + suffix == isc_log_rollsuffix_increment) + { + return (ISC_R_SUCCESS); + } else { + return (ISC_R_INVALIDFILE); + } } env->max_size = max_size; env->rolls = rolls; + env->suffix = suffix; return (ISC_R_SUCCESS); } @@ -310,14 +323,16 @@ dns_dt_reopen(dns_dtenv_t *env, int roll) { * Check that we can create a new fw object. */ fwopt = fstrm_writer_options_init(); - if (fwopt == NULL) + if (fwopt == NULL) { return (ISC_R_NOMEMORY); + } res = fstrm_writer_options_add_content_type(fwopt, DNSTAP_CONTENT_TYPE, sizeof(DNSTAP_CONTENT_TYPE) - 1); - if (res != fstrm_res_success) + if (res != fstrm_res_success) { CHECK(ISC_R_FAILURE); + } if (env->mode == dns_dtmode_file) { ffwopt = fstrm_file_options_init(); @@ -332,11 +347,13 @@ dns_dt_reopen(dns_dtenv_t *env, int roll) { env->path); fw = fstrm_unix_writer_init(fuwopt, fwopt); } - } else + } else { CHECK(ISC_R_NOTIMPLEMENTED); + } - if (fw == NULL) + if (fw == NULL) { CHECK(ISC_R_FAILURE); + } /* * We are committed here. @@ -349,10 +366,15 @@ dns_dt_reopen(dns_dtenv_t *env, int roll) { generation++; - if (env->iothr != NULL) + if (env->iothr != NULL) { fstrm_iothr_destroy(&env->iothr); + } + + if (roll != 0) { + roll = env->rolls; + } - if (env->mode == dns_dtmode_file && roll >= 0) { + if (env->mode == dns_dtmode_file && roll != 0) { /* * Create a temporary isc_logfile_t structure so we can * take advantage of the logfile rolling facility. @@ -360,9 +382,10 @@ dns_dt_reopen(dns_dtenv_t *env, int roll) { char *filename = isc_mem_strdup(env->mctx, env->path); file.name = filename; file.stream = NULL; - file.versions = roll != 0 ? roll : ISC_LOG_ROLLINFINITE; + file.versions = roll != 0 ? roll : env->rolls; file.maximum_size = 0; file.maximum_reached = ISC_FALSE; + file.suffix = env->suffix; result = isc_logfile_roll(&file); isc_mem_free(env->mctx, filename); CHECK(result); @@ -714,7 +737,8 @@ dns_dt_send(dns_view_t *view, dns_dtmsgtype_t msgtype, if (view->dtenv->max_size != 0) { struct stat statbuf; if (stat(view->dtenv->path, &statbuf) >= 0 && - (size_t) statbuf.st_size > view->dtenv->max_size) { + statbuf.st_size > view->dtenv->max_size) + { dns_dt_reopen(view->dtenv, view->dtenv->rolls); } } diff --git a/lib/dns/include/dns/dnstap.h b/lib/dns/include/dns/dnstap.h index 81f27067757..df3379cdf6c 100644 --- a/lib/dns/include/dns/dnstap.h +++ b/lib/dns/include/dns/dnstap.h @@ -28,6 +28,7 @@ struct fstrm_iothr_options; #endif /* HAVE_DNSTAP */ +#include #include #include #include @@ -153,7 +154,8 @@ dns_dt_create(isc_mem_t *mctx, dns_dtmode_t mode, const char *path, */ isc_result_t -dns_dt_setupfile(dns_dtenv_t *env, isc_uint64_t max_size, int rolls); +dns_dt_setupfile(dns_dtenv_t *env, isc_uint64_t max_size, int rolls, + isc_log_rollsuffix_t suffix); /*%< * Sets up the dnstap logfile limits. * @@ -161,6 +163,8 @@ dns_dt_setupfile(dns_dtenv_t *env, isc_uint64_t max_size, int rolls); * * 'rolls' is the number of rolled files to retain. * + * 'suffix' is the logfile suffix setting, increment or timestamp. + * * Requires: * *\li 'env' is a valid dnstap environment. diff --git a/lib/isc/include/isc/log.h b/lib/isc/include/isc/log.h index e77bafd0eff..03904b5f16f 100644 --- a/lib/isc/include/isc/log.h +++ b/lib/isc/include/isc/log.h @@ -78,6 +78,17 @@ */ #define ISC_LOG_ROLLINFINITE (-1) #define ISC_LOG_ROLLNEVER (-2) +#define ISC_LOG_MAX_VERSIONS 256 +/*@}*/ + +/*@{*/ +/*! + * \brief Type of suffix used on rolled log files. + */ +typedef enum { + isc_log_rollsuffix_increment, + isc_log_rollsuffix_timestamp +} isc_log_rollsuffix_t; /*@}*/ /*! @@ -115,6 +126,7 @@ typedef struct isc_logfile { FILE *stream; /*%< Initialized to NULL for #ISC_LOG_TOFILE. */ const char *name; /*%< NULL for #ISC_LOG_TOFILEDESC. */ int versions; /* >= 0, #ISC_LOG_ROLLNEVER, #ISC_LOG_ROLLINFINITE. */ + isc_log_rollsuffix_t suffix; /*% * stdio's ftell is standardized to return a long, which may well not * be big enough for the largest file supportable by the operating diff --git a/lib/isc/log.c b/lib/isc/log.c index 0b68d9233b4..5526c075964 100644 --- a/lib/isc/log.c +++ b/lib/isc/log.c @@ -241,6 +241,7 @@ isc_log_doit(isc_log_t *lctx, isc_logcategory_t *category, #define FILE_NAME(channel) (channel->destination.file.name) #define FILE_STREAM(channel) (channel->destination.file.stream) #define FILE_VERSIONS(channel) (channel->destination.file.versions) +#define FILE_SUFFIX(channel) (channel->destination.file.suffix) #define FILE_MAXSIZE(channel) (channel->destination.file.maximum_size) #define FILE_MAXREACHED(channel) (channel->destination.file.maximum_reached) @@ -365,6 +366,7 @@ isc_logconfig_create(isc_log_t *lctx, isc_logconfig_t **lcfgp) { destination.file.stream = stderr; destination.file.name = NULL; destination.file.versions = ISC_LOG_ROLLNEVER; + destination.file.suffix = isc_log_rollsuffix_increment; destination.file.maximum_size = 0; result = isc_log_createchannel(lcfg, "default_stderr", ISC_LOG_TOFILEDESC, @@ -384,6 +386,7 @@ isc_logconfig_create(isc_log_t *lctx, isc_logconfig_t **lcfgp) { destination.file.stream = stderr; destination.file.name = NULL; destination.file.versions = ISC_LOG_ROLLNEVER; + destination.file.suffix = isc_log_rollsuffix_increment; destination.file.maximum_size = 0; result = isc_log_createchannel(lcfg, "default_debug", ISC_LOG_TOFILEDESC, @@ -742,6 +745,7 @@ isc_log_createchannel(isc_logconfig_t *lcfg, const char *name, isc_mem_strdup(mctx, destination->file.name); FILE_STREAM(channel) = NULL; FILE_VERSIONS(channel) = destination->file.versions; + FILE_SUFFIX(channel) = destination->file.suffix; FILE_MAXSIZE(channel) = destination->file.maximum_size; FILE_MAXREACHED(channel) = ISC_FALSE; break; @@ -751,6 +755,7 @@ isc_log_createchannel(isc_logconfig_t *lcfg, const char *name, FILE_STREAM(channel) = destination->file.stream; FILE_MAXSIZE(channel) = 0; FILE_VERSIONS(channel) = ISC_LOG_ROLLNEVER; + FILE_SUFFIX(channel) = isc_log_rollsuffix_increment; break; case ISC_LOG_TONULL: @@ -1210,23 +1215,134 @@ greatest_version(isc_logfile_t *file, int versions, int *greatestp) { return (ISC_R_SUCCESS); } -isc_result_t -isc_logfile_roll(isc_logfile_t *file) { - int i, n, greatest; - char current[PATH_MAX + 1]; - char new[PATH_MAX + 1]; - const char *path; +static isc_result_t +remove_old_tsversions(isc_logfile_t *file, int versions) { isc_result_t result; + char *bname, *digit_end; + const char *dirname; + isc_int64_t version, last = ISC_INT64_MAX; + isc_int64_t to_keep[ISC_LOG_MAX_VERSIONS]; + size_t bnamelen; + isc_dir_t dir; + char sep = '/'; +#ifdef _WIN32 + char *bname2; +#endif + /* + * It is safe to DE_CONST the file.name because it was copied + * with isc_mem_strdup(). + */ + bname = strrchr(file->name, sep); +#ifdef _WIN32 + bname2 = strrchr(file->name, '\\'); + if ((bname != NULL && bname2 != NULL && bname2 > bname) || + (bname == NULL && bname2 != NULL)) { + bname = bname2; + sep = '\\'; + } +#endif + if (bname != NULL) { + *bname++ = '\0'; + dirname = file->name; + } else { + DE_CONST(file->name, bname); + dirname = "."; + } + bnamelen = strlen(bname); - REQUIRE(file != NULL); + isc_dir_init(&dir); + result = isc_dir_open(&dir, dirname); /* - * Do nothing (not even excess version trimming) if ISC_LOG_ROLLNEVER - * is specified. Apparently complete external control over the log - * files is desired. + * Replace the file separator if it was taken out. */ - if (file->versions == ISC_LOG_ROLLNEVER) - return (ISC_R_SUCCESS); + if (bname != file->name) { + *(bname - 1) = sep; + } + + /* + * Return if the directory open failed. + */ + if (result != ISC_R_SUCCESS) + return (result); + + if (versions > 0) { + /* + * First we fill 'to_keep' structure using insertion sort + */ + memset(to_keep, 0, versions * sizeof(long long)); + while (isc_dir_read(&dir) == ISC_R_SUCCESS) { + if (dir.entry.length > bnamelen && + strncmp(dir.entry.name, bname, bnamelen) == 0 && + dir.entry.name[bnamelen] == '.') + { + version = strtoll(&dir.entry.name[bnamelen + 1], + &digit_end, 10); + if (*digit_end == '\0') { + int i = 0; + while (version < to_keep[i] && + i < versions) + { + i++; + } + if (i < versions) { + memmove(&to_keep[i + 1], + &to_keep[i], + sizeof(long long) * + versions - i - 1); + to_keep[i] = version; + } + } + } + } + + /* + * to_keep[versions - 1] is the last one we want to keep + */ + last = to_keep[versions - 1]; + isc_dir_reset(&dir); + } + + /* + * Then we remove all files that we don't want to_keep + */ + while (isc_dir_read(&dir) == ISC_R_SUCCESS) { + if (dir.entry.length > bnamelen && + strncmp(dir.entry.name, bname, bnamelen) == 0 && + dir.entry.name[bnamelen] == '.') + { + version = strtoll(&dir.entry.name[bnamelen + 1], + &digit_end, 10); + /* + * Remove any backup files that exceed versions. + */ + if (*digit_end == '\0' && version < last) { + result = isc_file_remove(dir.entry.name); + if (result != ISC_R_SUCCESS && + result != ISC_R_FILENOTFOUND) + syslog(LOG_ERR, "unable to remove " + "log file '%s': %s", + dir.entry.name, + isc_result_totext(result)); + } + } + } + + isc_dir_close(&dir); + + return (ISC_R_SUCCESS); +} + +static isc_result_t +roll_increment(isc_logfile_t *file) { + int i, n, greatest; + char current[PATH_MAX + 1]; + char newpath[PATH_MAX + 1]; + const char *path; + isc_result_t result = ISC_R_SUCCESS; + + REQUIRE(file != NULL); + REQUIRE(file->versions != 0); path = file->name; @@ -1237,10 +1353,11 @@ isc_logfile_roll(isc_logfile_t *file) { for (greatest = 0; greatest < INT_MAX; greatest++) { n = snprintf(current, sizeof(current), "%s.%u", path, greatest) ; - if (n >= (int)sizeof(current) || n < 0) - break; - if (!isc_file_exists(current)) + if (n >= (int)sizeof(current) || n < 0 || + !isc_file_exists(current)) + { break; + } } } else { /* @@ -1248,56 +1365,129 @@ isc_logfile_roll(isc_logfile_t *file) { * version greater than the permitted version. */ result = greatest_version(file, file->versions, &greatest); - if (result != ISC_R_SUCCESS) + if (result != ISC_R_SUCCESS) { return (result); + } /* * Increment if greatest is not the actual maximum value. */ - if (greatest < file->versions - 1) + if (greatest < file->versions - 1) { greatest++; + } } for (i = greatest; i > 0; i--) { result = ISC_R_SUCCESS; n = snprintf(current, sizeof(current), "%s.%u", path, i - 1); - if (n >= (int)sizeof(current) || n < 0) + if (n >= (int)sizeof(current) || n < 0) { result = ISC_R_NOSPACE; + } if (result == ISC_R_SUCCESS) { - n = snprintf(new, sizeof(new), "%s.%u", path, i); - if (n >= (int)sizeof(new) || n < 0) + n = snprintf(newpath, sizeof(newpath), "%s.%u", + path, i); + if (n >= (int)sizeof(newpath) || n < 0) { result = ISC_R_NOSPACE; + } } - if (result == ISC_R_SUCCESS) - result = isc_file_rename(current, new); - if (result != ISC_R_SUCCESS && - result != ISC_R_FILENOTFOUND) + if (result == ISC_R_SUCCESS) { + result = isc_file_rename(current, newpath); + } + if (result != ISC_R_SUCCESS && result != ISC_R_FILENOTFOUND) { syslog(LOG_ERR, "unable to rename log file '%s.%u' to " "'%s.%u': %s", path, i - 1, path, i, isc_result_totext(result)); + } } - if (file->versions != 0) { - n = snprintf(new, sizeof(new), "%s.0", path); - if (n >= (int)sizeof(new) || n < 0) - result = ISC_R_NOSPACE; - else - result = isc_file_rename(path, new); - if (result != ISC_R_SUCCESS && - result != ISC_R_FILENOTFOUND) - syslog(LOG_ERR, - "unable to rename log file '%s' to '%s.0': %s", - path, path, isc_result_totext(result)); + n = snprintf(newpath, sizeof(newpath), "%s.0", path); + if (n >= (int)sizeof(newpath) || n < 0) { + result = ISC_R_NOSPACE; + } else { + result = isc_file_rename(path, newpath); + } + if (result != ISC_R_SUCCESS && result != ISC_R_FILENOTFOUND) { + syslog(LOG_ERR, + "unable to rename log file '%s' to '%s.0': %s", + path, path, isc_result_totext(result)); + } + + return (ISC_R_SUCCESS); +} + +static isc_result_t +roll_timestamp(isc_logfile_t *file) { + int n; + char newts[PATH_MAX + 1]; + char newpath[PATH_MAX + 1]; + const char *path; + isc_time_t now; + isc_result_t result = ISC_R_SUCCESS; + + REQUIRE(file != NULL); + REQUIRE(file->versions != 0); + + path = file->name; + + /* + * First find all the logfiles and remove the oldest ones + * Save one fewer than file->versions because we'll be renaming + * the existing file to a timestamped version after this. + */ + if (file->versions != ISC_LOG_ROLLINFINITE) { + remove_old_tsversions(file, file->versions - 1); + } + + /* Then just rename the current logfile */ + isc_time_now(&now); + isc_time_formatshorttimestamp(&now, newts, PATH_MAX + 1); + n = snprintf(newpath, sizeof(newpath), "%s.%s", path, newts); + if (n >= (int)sizeof(newpath) || n < 0) { + result = ISC_R_NOSPACE; } else { - result = isc_file_remove(path); + result = isc_file_rename(path, newpath); + } + if (result != ISC_R_SUCCESS && result != ISC_R_FILENOTFOUND) { + syslog(LOG_ERR, + "unable to rename log file '%s' to '%s.0': %s", + path, path, isc_result_totext(result)); + } + + return (ISC_R_SUCCESS); +} + + +isc_result_t +isc_logfile_roll(isc_logfile_t *file) { + isc_result_t result; + + REQUIRE(file != NULL); + + /* + * Do nothing (not even excess version trimming) if ISC_LOG_ROLLNEVER + * is specified. Apparently complete external control over the log + * files is desired. + */ + if (file->versions == ISC_LOG_ROLLNEVER) { + return (ISC_R_SUCCESS); + } else if (file->versions == 0) { + result = isc_file_remove(file->name); if (result != ISC_R_SUCCESS && result != ISC_R_FILENOTFOUND) syslog(LOG_ERR, "unable to remove log file '%s': %s", - path, isc_result_totext(result)); + file->name, isc_result_totext(result)); + return (ISC_R_SUCCESS); } - return (ISC_R_SUCCESS); + switch (file->suffix) { + case isc_log_rollsuffix_increment: + return (roll_increment(file)); + case isc_log_rollsuffix_timestamp: + return (roll_timestamp(file)); + default: + return (ISC_R_UNEXPECTED); + } } static isc_result_t diff --git a/lib/isc/unix/include/isc/time.h b/lib/isc/unix/include/isc/time.h index 47ccd530981..b6bfdc9b2ba 100644 --- a/lib/isc/unix/include/isc/time.h +++ b/lib/isc/unix/include/isc/time.h @@ -379,6 +379,20 @@ isc_time_formatISO8601ms(const isc_time_t *t, char *buf, unsigned int len); * */ +void +isc_time_formatshorttimestamp(const isc_time_t *t, char *buf, unsigned int len); +/*%< + * Format the time 't' into the buffer 'buf' of length 'len', + * using the format "yyyymmddhhmmsssss" userful for file timestamping. + * If the text does not fit in the buffer, the result is indeterminate, + * but is always guaranteed to be null terminated. + * + * Requires: + *\li 'len' > 0 + *\li 'buf' points to an array of at least len chars + * + */ + ISC_LANG_ENDDECLS #endif /* ISC_TIME_H */ diff --git a/lib/isc/unix/time.c b/lib/isc/unix/time.c index f7d40306f0b..f1b7f2274d6 100644 --- a/lib/isc/unix/time.c +++ b/lib/isc/unix/time.c @@ -480,3 +480,21 @@ isc_time_formatISO8601ms(const isc_time_t *t, char *buf, unsigned int len) { t->nanoseconds / NS_PER_MS); } } + +void +isc_time_formatshorttimestamp(const isc_time_t *t, char *buf, unsigned int len) +{ + time_t now; + unsigned int flen; + + REQUIRE(len > 0); + + now = (time_t)t->seconds; + flen = strftime(buf, len, "%Y%m%d%H%M%S", gmtime(&now)); + INSIST(flen < len); + if (flen > 0U && len - flen >= 5) { + flen -= 1; /* rewind one character (Z) */ + snprintf(buf + flen, len - flen, "%03u", + t->nanoseconds / NS_PER_MS); + } +} diff --git a/lib/isc/win32/include/isc/time.h b/lib/isc/win32/include/isc/time.h index 4b244dba95d..a9aa481272a 100644 --- a/lib/isc/win32/include/isc/time.h +++ b/lib/isc/win32/include/isc/time.h @@ -343,6 +343,20 @@ isc_time_formatISO8601ms(const isc_time_t *t, char *buf, unsigned int len); * */ +void +isc_time_formatshorttimestamp(const isc_time_t *t, char *buf, unsigned int len); +/*%< + * Format the time 't' into the buffer 'buf' of length 'len', + * using the format "yyyymmddhhmmsssss" userful for file timestamping. + * If the text does not fit in the buffer, the result is indeterminate, + * but is always guaranteed to be null terminated. + * + * Requires: + *\li 'len' > 0 + *\li 'buf' points to an array of at least len chars + * + */ + isc_uint32_t isc_time_seconds(const isc_time_t *t); /*%< diff --git a/lib/isc/win32/libisc.def.in b/lib/isc/win32/libisc.def.in index efb747da809..2bb4a3c0669 100644 --- a/lib/isc/win32/libisc.def.in +++ b/lib/isc/win32/libisc.def.in @@ -710,6 +710,7 @@ isc_time_compare isc_time_formatISO8601 isc_time_formatISO8601ms isc_time_formathttptimestamp +isc_time_formatshorttimestamp isc_time_formattimestamp isc_time_isepoch isc_time_microdiff diff --git a/lib/isc/win32/time.c b/lib/isc/win32/time.c index 43e9a84ec14..116151ead9f 100644 --- a/lib/isc/win32/time.c +++ b/lib/isc/win32/time.c @@ -413,3 +413,26 @@ isc_time_formatISO8601ms(const isc_time_t *t, char *buf, unsigned int len) { buf[0] = 0; } } + +void +isc_time_formatshorttimestamp(const isc_time_t *t, char *buf, unsigned int len) +{ + SYSTEMTIME st; + char DateBuf[50]; + char TimeBuf[50]; + + /* strtime() format: "%Y%m%d%H%M%SSSS" */ + + REQUIRE(len > 0); + if (FileTimeToSystemTime(&t->absolute, &st)) { + GetDateFormat(LOCALE_NEUTRAL, 0, &st, "yyyyMMdd", + DateBuf, 50); + GetTimeFormat(LOCALE_NEUTRAL, + TIME_NOTIMEMARKER | TIME_FORCE24HOURFORMAT, + &st, "hhmmss", TimeBuf, 50); + snprintf(buf, len, "%s%s%03u", DateBuf, TimeBuf, + st.wMilliseconds); + } else { + buf[0] = 0; + } +} diff --git a/lib/isccfg/namedconf.c b/lib/isccfg/namedconf.c index badbcf9af72..63f5048efa9 100644 --- a/lib/isccfg/namedconf.c +++ b/lib/isccfg/namedconf.c @@ -107,6 +107,7 @@ static cfg_type_t cfg_type_key; static cfg_type_t cfg_type_logfile; static cfg_type_t cfg_type_logging; static cfg_type_t cfg_type_logseverity; +static cfg_type_t cfg_type_logsuffix; static cfg_type_t cfg_type_logversions; static cfg_type_t cfg_type_lwres; static cfg_type_t cfg_type_masterselement; @@ -1327,6 +1328,11 @@ parse_dtout(cfg_parser_t *pctx, const cfg_type_t *type, cfg_obj_t **ret) { { CHECK(cfg_parse_obj(pctx, fields[3].type, &obj->value.tuple[3])); + } else if (strcasecmp(TOKEN_STRING(pctx), + "suffix") == 0 && + obj->value.tuple[4] == NULL) { + CHECK(cfg_parse_obj(pctx, fields[4].type, + &obj->value.tuple[4])); } else { cfg_parser_error(pctx, CFG_LOG_NEAR, "unexpected token"); @@ -1343,6 +1349,8 @@ parse_dtout(cfg_parser_t *pctx, const cfg_type_t *type, cfg_obj_t **ret) { CHECK(cfg_parse_void(pctx, NULL, &obj->value.tuple[2])); if (obj->value.tuple[3] == NULL) CHECK(cfg_parse_void(pctx, NULL, &obj->value.tuple[3])); + if (obj->value.tuple[4] == NULL) + CHECK(cfg_parse_void(pctx, NULL, &obj->value.tuple[4])); *ret = obj; return (ISC_R_SUCCESS); @@ -1364,6 +1372,10 @@ print_dtout(cfg_printer_t *pctx, const cfg_obj_t *obj) { cfg_print_cstr(pctx, " versions "); cfg_print_obj(pctx, obj->value.tuple[3]); } + if (obj->value.tuple[4]->type->print != cfg_print_void) { + cfg_print_cstr(pctx, " suffix "); + cfg_print_obj(pctx, obj->value.tuple[4]); + } } @@ -1375,6 +1387,8 @@ doc_dtout(cfg_printer_t *pctx, const cfg_type_t *type) { cfg_print_cstr(pctx, "[ size ( unlimited | ) ]"); cfg_print_cstr(pctx, " "); cfg_print_cstr(pctx, "[ versions ( unlimited | ) ]"); + cfg_print_cstr(pctx, " "); + cfg_print_cstr(pctx, "[ suffix ( increment | timestamp ) ]"); } static const char *dtoutmode_enums[] = { "file", "unix", NULL }; @@ -1388,6 +1402,7 @@ static cfg_tuplefielddef_t dtout_fields[] = { { "path", &cfg_type_qstring, 0 }, { "size", &cfg_type_sizenodefault, 0 }, { "versions", &cfg_type_logversions, 0 }, + { "suffix", &cfg_type_logsuffix, 0 }, { NULL, NULL, 0 } }; @@ -3393,10 +3408,17 @@ static cfg_type_t cfg_type_logversions = { &cfg_rep_string, logversions_enums }; +static const char *logsuffix_enums[] = { "increment", "timestamp", NULL }; +static cfg_type_t cfg_type_logsuffix = { + "logsuffix", cfg_parse_enum, cfg_print_ustring, cfg_doc_enum, + &cfg_rep_string, &logsuffix_enums +}; + static cfg_tuplefielddef_t logfile_fields[] = { { "file", &cfg_type_qstring, 0 }, { "versions", &cfg_type_logversions, 0 }, { "size", &cfg_type_size, 0 }, + { "suffix", &cfg_type_logsuffix, 0 }, { NULL, NULL, 0 } }; @@ -3426,6 +3448,11 @@ parse_logfile(cfg_parser_t *pctx, const cfg_type_t *type, cfg_obj_t **ret) { obj->value.tuple[2] == NULL) { CHECK(cfg_parse_obj(pctx, fields[2].type, &obj->value.tuple[2])); + } else if (strcasecmp(TOKEN_STRING(pctx), + "suffix") == 0 && + obj->value.tuple[3] == NULL) { + CHECK(cfg_parse_obj(pctx, fields[3].type, + &obj->value.tuple[3])); } else { break; } @@ -3439,6 +3466,8 @@ parse_logfile(cfg_parser_t *pctx, const cfg_type_t *type, cfg_obj_t **ret) { CHECK(cfg_parse_void(pctx, NULL, &obj->value.tuple[1])); if (obj->value.tuple[2] == NULL) CHECK(cfg_parse_void(pctx, NULL, &obj->value.tuple[2])); + if (obj->value.tuple[3] == NULL) + CHECK(cfg_parse_void(pctx, NULL, &obj->value.tuple[3])); *ret = obj; return (ISC_R_SUCCESS); @@ -3459,6 +3488,10 @@ print_logfile(cfg_printer_t *pctx, const cfg_obj_t *obj) { cfg_print_cstr(pctx, " size "); cfg_print_obj(pctx, obj->value.tuple[2]); } + if (obj->value.tuple[3]->type->print != cfg_print_void) { + cfg_print_cstr(pctx, " suffix "); + cfg_print_obj(pctx, obj->value.tuple[3]); + } } @@ -3467,9 +3500,11 @@ doc_logfile(cfg_printer_t *pctx, const cfg_type_t *type) { UNUSED(type); cfg_print_cstr(pctx, ""); cfg_print_cstr(pctx, " "); - cfg_print_cstr(pctx, "[ versions ( \"unlimited\" | ) ]"); + cfg_print_cstr(pctx, "[ versions ( unlimited | ) ]"); cfg_print_cstr(pctx, " "); cfg_print_cstr(pctx, "[ size ]"); + cfg_print_cstr(pctx, " "); + cfg_print_cstr(pctx, "[ suffix ( increment | timestamp ) ]"); } static cfg_type_t cfg_type_logfile = {