Commit 62c85a4a authored by Evan Hunt's avatar Evan Hunt
Browse files

[master] allow different time formats: local, iso8601, iso8601-utc

4518.	[func]		The "print-time" option in the logging configuration
			can now take arguments "local", "iso8601" or
			"iso8601-utc" to indicate the format in which the
			date and time should be logged. For backward
			compatibility, "yes" is a synonym for "local".
			[RT #42585]
parent f26fab11
4518. [func] The "print-time" option in the logging configuration
can now take arguments "local", "iso8601" or
"iso8601-utc" to indicate the format in which the
date and time should be logged. For backward
compatibility, "yes" is a synonym for "local".
[RT #42585]
4517. [placeholder]
4516. [bug] isc_socketmgr_renderjson was missing from the
......
......@@ -87,8 +87,7 @@ category_fromconf(const cfg_obj_t *ccat, isc_logconfig_t *logconfig) {
* in 'cchan' and add it to 'logconfig'.
*/
static isc_result_t
channel_fromconf(const cfg_obj_t *channel, isc_logconfig_t *logconfig)
{
channel_fromconf(const cfg_obj_t *channel, isc_logconfig_t *logconfig) {
isc_result_t result;
isc_logdestination_t dest;
unsigned int type;
......@@ -202,12 +201,21 @@ channel_fromconf(const cfg_obj_t *channel, isc_logconfig_t *logconfig)
if (printcat != NULL && cfg_obj_asboolean(printcat))
flags |= ISC_LOG_PRINTCATEGORY;
if (printtime != NULL && cfg_obj_asboolean(printtime))
flags |= ISC_LOG_PRINTTIME;
if (printsev != NULL && cfg_obj_asboolean(printsev))
flags |= ISC_LOG_PRINTLEVEL;
if (buffered != NULL && cfg_obj_asboolean(buffered))
flags |= ISC_LOG_BUFFERED;
if (printtime != NULL && cfg_obj_isboolean(printtime)) {
if (cfg_obj_asboolean(printtime))
flags |= ISC_LOG_PRINTTIME;
} else if (printtime != NULL) { /* local/iso8601/iso8601-utc */
const char *s = cfg_obj_asstring(printtime);
flags |= ISC_LOG_PRINTTIME;
if (strcasecmp(s, "iso8601") == 0)
flags |= ISC_LOG_ISO8601;
else if (strcasecmp(s, "iso8601-utc") == 0)
flags |= ISC_LOG_ISO8601 | ISC_LOG_UTC;
}
}
level = ISC_LOG_INFO;
......
/*
* 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/.
*/
logging {
channel one {
file "one.out";
print-time bogus;
};
};
/*
* 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/.
*/
logging {
channel one {
file "one.out";
print-time no;
};
channel two {
file "two.out";
print-time yes;
};
channel three {
file "three.out";
print-time local;
};
channel four {
file "four.out";
print-time iso8601;
};
channel five {
file "five.out";
print-time iso8601-utc;
};
};
......@@ -6,8 +6,6 @@
# 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/.
# $Id: clean.sh,v 1.4 2011/03/22 16:51:50 smann Exp $
#
# Clean up after log file tests
#
......@@ -19,4 +17,6 @@ rm -rf ns1/named_dir
rm -f ns1/named_deflog
rm -f ns*/named.lock
rm -f ns1/query_log
rm -f ns1/named_iso8601
rm -f ns1/named_iso8601_utc
rm -f ns1/rndc.out.test*
/*
* 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 {
file "named_iso8601";
print-time iso8601;
severity debug 9;
};
category default { default_log; default_debug; };
};
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";
};
/*
* 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 {
file "named_iso8601_utc";
print-time iso8601-utc;
severity debug 9;
};
category default { default_log; default_debug; };
};
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";
};
......@@ -12,16 +12,19 @@ SYSTEMTESTTOP=..
. $SYSTEMTESTTOP/conf.sh
THISDIR=`pwd`
CONFDIR="ns1"
PLAINCONF="${THISDIR}/${CONFDIR}/named.plain"
DIRCONF="${THISDIR}/${CONFDIR}/named.dirconf"
PIPECONF="${THISDIR}/${CONFDIR}/named.pipeconf"
SYMCONF="${THISDIR}/${CONFDIR}/named.symconf"
PLAINCONF="${THISDIR}/${CONFDIR}/named.plainconf"
ISOCONF="${THISDIR}/${CONFDIR}/named.iso8601"
ISOCONFUTC="${THISDIR}/${CONFDIR}/named.iso8601-utc"
PLAINFILE="named_log"
DIRFILE="named_dir"
PIPEFILE="named_pipe"
SYMFILE="named_sym"
DLFILE="named_deflog"
ISOFILE="named_iso8601"
ISOUTCFILE="named_iso8601_utc"
PIDFILE="${THISDIR}/${CONFDIR}/named.pid"
myRNDC="$RNDC -c ${THISDIR}/${CONFDIR}/rndc.conf"
myNAMED="$NAMED -c ${THISDIR}/${CONFDIR}/named.conf -m record,size,mctx -T clienttest -T nosyslog -d 99 -X named.lock -U 4"
......@@ -238,10 +241,8 @@ else
echo "I: skipping symlink test (unable to create symlink)"
fi
status=0
n=`expr $n + 1`
echo "I:testing default logfile using named -L file ($n)"
echo "I: testing default logfile using named -L file ($n)"
# Now stop the server again and test the -L option
rm -f $DLFILE
$PERL ../../stop.pl .. ns1
......@@ -270,5 +271,29 @@ else
exit 1
fi
echo "I:testing logging functionality"
n=`expr $n + 1`
echo "I: testing iso8601 timestamp ($n)"
cp $ISOCONF named.conf
$myRNDC reconfig > rndc.out.test$n 2>&1
if grep '^....-..-..T..:..:..\.... ' $ISOFILE > /dev/null; then
echo "I: testing iso8601 timestamp succeeded"
else
echo "I: testing iso8601 timestamp failed"
status=`expr $status + 1`
fi
n=`expr $n + 1`
echo "I: testing iso8601-utc timestamp ($n)"
cp $ISOCONFUTC named.conf
$myRNDC reconfig > rndc.out.test$n 2>&1
if grep '^....-..-..T..:..:..\....Z' $ISOUTCFILE > /dev/null; then
echo "I: testing iso8601-utc timestamp succeeded"
else
echo "I: testing iso8601-utc timestamp failed"
status=`expr $status + 1`
fi
echo "I:exit status: $status"
[ $status -eq 0 ] || exit 1
......@@ -3644,7 +3644,7 @@ $ORIGIN 0.0.0.0.0.0.0.0.8.b.d.0.1.0.0.2.ip6.arpa.
<option>info</option> | <option>debug</option> [ <replaceable>level</replaceable> ] | <option>dynamic</option> ); ]
[ <command>print-category</command> <option>yes</option> or <option>no</option>; ]
[ <command>print-severity</command> <option>yes</option> or <option>no</option>; ]
[ <command>print-time</command> <option>yes</option> or <option>no</option>; ]
[ <command>print-time</command> ( <option>>yes</option> | <option>no</option> | <option>local</option> | <option>iso8601</option> | <option>iso8601-utc</option> ) ;
[ <command>buffered</command> <option>yes</option> or <option>no</option>; ]
}; ]
[ <command>category</command> <replaceable>category_name</replaceable> {
......@@ -3877,14 +3877,30 @@ notrace</command>. All debugging messages in the server have a debug
server's global debug level to determine what messages to print.
</para>
<para>
If <command>print-time</command> has been turned on,
then
the date and time will be logged. <command>print-time</command> may
<command>print-time</command> can be set to
<userinput>yes</userinput>, <userinput>no</userinput>,
or a time format specifier, which may be one of
<option>local</option>, <option>iso8601</option> or
<option>iso8601-utc</option>. If set to
<userinput>no</userinput>, then the date and time will
not be logged. If set to <userinput>yes</userinput>
or <option>local</option>, the date and time are logged
in a human readable format, using the local time zone.
If set to <option>iso8601</option> the local time is
logged in ISO8601 format. If set to
<option>iso8601-utc</option>, then the date and time
are logged in ISO8601 format, with time zone set to
UTC. The default is <option>local</option>.
</para>
<para>
<command>print-time</command> may
be specified for a <command>syslog</command> channel,
but is usually
but it is usually
pointless since <command>syslog</command> also logs
the date and
time. If <command>print-category</command> is
the date and time.
</para>
<para>
If <command>print-category</command> is
requested, then the
category of the message will be logged as well. Finally, if <command>print-severity</command> is
on, then the severity level of the message will be logged. The <command>print-</command> options may
......
......@@ -39,9 +39,10 @@
<listitem>
<para>
Added the ability to specify the maximum number of records
permitted in a zone (max-records #;). This provides a mechanism
to block overly large zone transfers, which is a potential risk
with slave zones from other parties, as described in CVE-2016-6170.
permitted in a zone (<option>max-records #;</option>).
This provides a mechanism to block overly large zone
transfers, which is a potential risk with slave zones from
other parties, as described in CVE-2016-6170.
[RT #42143]
</para>
</listitem>
......@@ -52,7 +53,13 @@
<itemizedlist>
<listitem>
<para>
None.
The <option>print-time</option> option in the
<option>logging</option> configuration can now take arguments
<userinput>local</userinput>, <userinput>iso8601</userinput> or
<userinput>iso8601-utc</userinput> to indicate the format in
which the date and time should be logged. For backward
compatibility, <userinput>yes</userinput> is a synonym for
<userinput>local</userinput>. [RT #42585]
</para>
</listitem>
</itemizedlist>
......
......@@ -54,16 +54,18 @@
/*%
* Channel flags.
*/
#define ISC_LOG_PRINTTIME 0x0001
#define ISC_LOG_PRINTLEVEL 0x0002
#define ISC_LOG_PRINTCATEGORY 0x0004
#define ISC_LOG_PRINTMODULE 0x0008
#define ISC_LOG_PRINTTAG 0x0010 /* tag and ":" */
#define ISC_LOG_PRINTPREFIX 0x0020 /* tag only, no colon */
#define ISC_LOG_PRINTALL 0x003F
#define ISC_LOG_BUFFERED 0x0040
#define ISC_LOG_DEBUGONLY 0x1000
#define ISC_LOG_OPENERR 0x8000 /* internal */
#define ISC_LOG_PRINTTIME 0x00001
#define ISC_LOG_PRINTLEVEL 0x00002
#define ISC_LOG_PRINTCATEGORY 0x00004
#define ISC_LOG_PRINTMODULE 0x00008
#define ISC_LOG_PRINTTAG 0x00010 /* tag and ":" */
#define ISC_LOG_PRINTPREFIX 0x00020 /* tag only, no colon */
#define ISC_LOG_PRINTALL 0x0003F
#define ISC_LOG_BUFFERED 0x00040
#define ISC_LOG_DEBUGONLY 0x01000
#define ISC_LOG_OPENERR 0x08000 /* internal */
#define ISC_LOG_ISO8601 0x10000 /* if PRINTTIME, use ISO8601 */
#define ISC_LOG_UTC 0x20000 /* if PRINTTIME, use UTC */
/*@}*/
/*@{*/
......
......@@ -697,7 +697,8 @@ isc_log_createchannel(isc_logconfig_t *lcfg, const char *name,
isc_logchannel_t *channel;
isc_mem_t *mctx;
unsigned int permitted = ISC_LOG_PRINTALL | ISC_LOG_DEBUGONLY |
ISC_LOG_BUFFERED;
ISC_LOG_BUFFERED | ISC_LOG_ISO8601 |
ISC_LOG_UTC;
REQUIRE(VALID_CONFIG(lcfg));
REQUIRE(name != NULL);
......@@ -1396,12 +1397,15 @@ isc_log_doit(isc_log_t *lctx, isc_logcategory_t *category,
const char *format, va_list args)
{
int syslog_level;
char time_string[64];
const char *time_string;
char local_time[64];
char iso8601z_string[64];
char iso8601l_string[64];
char level_string[24];
const char *iformat;
struct stat statbuf;
isc_boolean_t matched = ISC_FALSE;
isc_boolean_t printtime, printtag, printcolon;
isc_boolean_t printtime, iso8601, utc, printtag, printcolon;
isc_boolean_t printcategory, printmodule, printlevel, buffered;
isc_logconfig_t *lcfg;
isc_logchannel_t *channel;
......@@ -1433,7 +1437,9 @@ isc_log_doit(isc_log_t *lctx, isc_logcategory_t *category,
else
iformat = format;
time_string[0] = '\0';
local_time[0] = '\0';
iso8601l_string[0] = '\0';
iso8601z_string[0] = '\0';
level_string[0] = '\0';
LOCK(&lctx->lock);
......@@ -1496,12 +1502,21 @@ isc_log_doit(isc_log_t *lctx, isc_logcategory_t *category,
continue;
if ((channel->flags & ISC_LOG_PRINTTIME) != 0 &&
time_string[0] == '\0') {
local_time[0] == '\0')
{
isc_time_t isctime;
TIME_NOW(&isctime);
isc_time_formattimestamp(&isctime, time_string,
sizeof(time_string));
isc_time_formattimestamp(&isctime,
local_time,
sizeof(local_time));
isc_time_formatISO8601ms(&isctime,
iso8601z_string,
sizeof(iso8601z_string));
isc_time_formatISO8601Lms(&isctime,
iso8601l_string,
sizeof(iso8601l_string));
}
if ((channel->flags & ISC_LOG_PRINTLEVEL) != 0 &&
......@@ -1628,6 +1643,8 @@ isc_log_doit(isc_log_t *lctx, isc_logcategory_t *category,
}
}
utc = ISC_TF((channel->flags & ISC_LOG_UTC) != 0);
iso8601 = ISC_TF((channel->flags & ISC_LOG_ISO8601) != 0);
printtime = ISC_TF((channel->flags & ISC_LOG_PRINTTIME)
!= 0);
printtag = ISC_TF((channel->flags &
......@@ -1644,6 +1661,19 @@ isc_log_doit(isc_log_t *lctx, isc_logcategory_t *category,
buffered = ISC_TF((channel->flags & ISC_LOG_BUFFERED)
!= 0);
if (printtime) {
if (iso8601) {
if (utc) {
time_string = iso8601z_string;
} else {
time_string = iso8601l_string;
}
} else {
time_string = local_time;
}
} else
time_string = "";
switch (channel->type) {
case ISC_LOG_TOFILE:
if (FILE_MAXREACHED(channel)) {
......@@ -1691,7 +1721,7 @@ isc_log_doit(isc_log_t *lctx, isc_logcategory_t *category,
case ISC_LOG_TOFILEDESC:
fprintf(FILE_STREAM(channel),
"%s%s%s%s%s%s%s%s%s%s\n",
printtime ? time_string : "",
printtime ? time_string : "",
printtime ? " " : "",
printtag ? lcfg->tag : "",
printcolon ? ": " : "",
......
......@@ -8,6 +8,7 @@
#include <config.h>
#include <stdlib.h>
#include <string.h>
#include <atf-c.h>
......@@ -33,11 +34,118 @@ ATF_TC_BODY(isc_time_parsehttptimestamp, tc) {
ATF_REQUIRE_EQ(isc_time_seconds(&t), isc_time_seconds(&x));
}
ATF_TC(isc_time_formatISO8601);
ATF_TC_HEAD(isc_time_formatISO8601, tc) {
atf_tc_set_md_var(tc, "descr", "print UTC in ISO8601");
}
ATF_TC_BODY(isc_time_formatISO8601, tc) {
isc_result_t result;
isc_time_t t;
char buf[64];
setenv("TZ", "PST8PDT", 1);
result = isc_time_now(&t);
ATF_REQUIRE_EQ(result, ISC_R_SUCCESS);
/* yyyy-mm-ddThh:mm:ssZ */
memset(buf, 'X', sizeof(buf));
isc_time_formatISO8601(&t, buf, sizeof(buf));
ATF_CHECK_EQ(strlen(buf), 20);
ATF_CHECK_EQ(buf[4], '-');
ATF_CHECK_EQ(buf[7], '-');
ATF_CHECK_EQ(buf[10], 'T');
ATF_CHECK_EQ(buf[13], ':');
ATF_CHECK_EQ(buf[16], ':');
ATF_CHECK_EQ(buf[19], 'Z');
}
ATF_TC(isc_time_formatISO8601ms);
ATF_TC_HEAD(isc_time_formatISO8601ms, tc) {
atf_tc_set_md_var(tc, "descr",
"print UTC in ISO8601 with milliseconds");
}
ATF_TC_BODY(isc_time_formatISO8601ms, tc) {
isc_result_t result;
isc_time_t t;
char buf[64];
setenv("TZ", "PST8PDT", 1);
result = isc_time_now(&t);
ATF_REQUIRE_EQ(result, ISC_R_SUCCESS);
/* yyyy-mm-ddThh:mm:ss.sssZ */
memset(buf, 'X', sizeof(buf));
isc_time_formatISO8601ms(&t, buf, sizeof(buf));
ATF_CHECK_EQ(strlen(buf), 24);
ATF_CHECK_EQ(buf[4], '-');
ATF_CHECK_EQ(buf[7], '-');
ATF_CHECK_EQ(buf[10], 'T');
ATF_CHECK_EQ(buf[13], ':');
ATF_CHECK_EQ(buf[16], ':');
ATF_CHECK_EQ(buf[19], '.');
ATF_CHECK_EQ(buf[23], 'Z');
}
ATF_TC(isc_time_formatISO8601L);
ATF_TC_HEAD(isc_time_formatISO8601L, tc) {
atf_tc_set_md_var(tc, "descr",
"print local time in ISO8601");
}
ATF_TC_BODY(isc_time_formatISO8601L, tc) {
isc_result_t result;
isc_time_t t;
char buf[64];
setenv("TZ", "PST8PDT", 1);
result = isc_time_now(&t);
ATF_REQUIRE_EQ(result, ISC_R_SUCCESS);
/* yyyy-mm-ddThh:mm:ss */
memset(buf, 'X', sizeof(buf));
isc_time_formatISO8601L(&t, buf, sizeof(buf));
ATF_CHECK_EQ(strlen(buf), 19);
ATF_CHECK_EQ(buf[4], '-');
ATF_CHECK_EQ(buf[7], '-');
ATF_CHECK_EQ(buf[10], 'T');
ATF_CHECK_EQ(buf[13], ':');
ATF_CHECK_EQ(buf[16], ':');
}
ATF_TC(isc_time_formatISO8601Lms);
ATF_TC_HEAD(isc_time_formatISO8601Lms, tc) {
atf_tc_set_md_var(tc, "descr",
"print local time in ISO8601 with milliseconds");
}
ATF_TC_BODY(isc_time_formatISO8601Lms, tc) {
isc_result_t result;
isc_time_t t;
char buf[64];
setenv("TZ", "PST8PDT", 1);
result = isc_time_now(&t);
ATF_REQUIRE_EQ(result, ISC_R_SUCCESS);
/* yyyy-mm-ddThh:mm:ss.sss */
memset(buf, 'X', sizeof(buf));
isc_time_formatISO8601Lms(&t, buf, sizeof(buf));
ATF_CHECK_EQ(strlen(buf), 23);
ATF_CHECK_EQ(buf[4], '-');
ATF_CHECK_EQ(buf[7], '-');
ATF_CHECK_EQ(buf[10], 'T');
ATF_CHECK_EQ(buf[13], ':');
ATF_CHECK_EQ(buf[16], ':');
ATF_CHECK_EQ(buf[19], '.');
}
/*
* Main
*/
ATF_TP_ADD_TCS(tp) {
ATF_TP_ADD_TC(tp, isc_time_parsehttptimestamp);
ATF_TP_ADD_TC(tp, isc_time_formatISO8601);
ATF_TP_ADD_TC(tp, isc_time_formatISO8601ms);
ATF_TP_ADD_TC(tp, isc_time_formatISO8601L);
ATF_TP_ADD_TC(tp, isc_time_formatISO8601Lms);
return (atf_no_error());
}
......@@ -323,6 +323,34 @@ isc_time_parsehttptimestamp(char *input, isc_time_t *t);
*\li 'buf' and 't' are not NULL.
*/
void
isc_time_formatISO8601L(const isc_time_t *t, char *buf, unsigned int len);
/*%<
* Format the time 't' into the buffer 'buf' of length 'len',
* using the ISO8601 format: "yyyy-mm-ddThh:mm:ss"
* 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
*
*/
void
isc_time_formatISO8601Lms(const isc_time_t *t, char *buf, unsigned int len);
/*%<
* Format the time 't' into the buffer 'buf' of length 'len',
* using the ISO8601 format: "yyyy-mm-ddThh:mm:ss.sss"