EXTERN bool named_g_foreground INIT(false);
EXTERN bool named_g_logstderr INIT(false);
EXTERN bool named_g_nosyslog INIT(false);
+EXTERN unsigned int named_g_logflags INIT(0);
EXTERN const char *named_g_logfile INIT(NULL);
EXTERN const char *named_g_defaultsessionkeyfile INIT(NAMED_LOCALSTATEDIR
isc_log_createchannel(lcfg, "default_debug", ISC_LOG_TOFILE,
ISC_LOG_DYNAMIC, &destination,
ISC_LOG_PRINTTIME | ISC_LOG_DEBUGONLY);
+ } else if (named_g_logstderr && (named_g_logflags != 0)) {
+ /*
+ * If the option -g is given, but we also requested iso
+ * timestamps, we'll still need to override the "default_debug"
+ * logger with a new one.
+ */
+ isc_log_createchannel(lcfg, "default_debug", ISC_LOG_TOFILEDESC,
+ ISC_LOG_DYNAMIC,
+ ISC_LOGDESTINATION_STDERR,
+ ISC_LOG_PRINTTIME | named_g_logflags);
}
if (named_g_logfile != NULL) {
* discarded a bit faster.
*/
isc_log_setdebuglevel(0);
+ } else if (named_g_logstderr && (named_g_logflags != 0)) {
+ /*
+ * If the option -g is given, but we also requested iso
+ * timestamps, we'll still need to override the "default_debug"
+ * logger with a new one.
+ */
+ isc_log_createchannel(lcfg, "default_debug", ISC_LOG_TOFILEDESC,
+ ISC_LOG_DYNAMIC,
+ ISC_LOGDESTINATION_STDERR,
+ ISC_LOG_PRINTTIME | named_g_logflags);
} else {
isc_log_setdebuglevel(named_g_debuglevel);
}
flags |= ISC_LOG_ISO8601;
} else if (strcasecmp(s, "iso8601-utc") == 0) {
flags |= ISC_LOG_ISO8601 | ISC_LOG_UTC;
+ } else if (strcasecmp(s, "iso8601-tzinfo") == 0) {
+ flags |= ISC_LOG_ISO8601 | ISC_LOG_TZINFO;
}
}
}
case 'g':
named_g_foreground = true;
named_g_logstderr = true;
+ named_g_logflags = ISC_LOG_PRINTTIME | ISC_LOG_ISO8601 |
+ ISC_LOG_TZINFO;
break;
case 'L':
named_g_logfile = isc_commandline_argument;
n=$((n + 1))
echo_i "only one tcp socket was used ($n)"
-tcpclients=$(awk '$3 == "client" && $5 ~ /10.53.0.7#[0-9]*:/ {print $5}' ns2/named.run | sort | uniq -c | wc -l)
+tcpclients=$(awk '$2 == "client" && $4 ~ /10.53.0.7#[0-9]*:/ {print $4}' ns2/named.run | sort | uniq -c | wc -l)
test $tcpclients -eq 1 || {
status=1
file "five.out";
print-time iso8601-utc;
};
+ channel six {
+ file "six.out";
+ print-time iso8601-tzinfo;
+ };
};
# Get the latest next key event.
if [ "${DYNAMIC}" = "yes" ]; then
- _time=$(awk '{print $9}' <"keyevent.out.$ZONE.test$n" | tail -1)
+ _time=$(awk '{print $8}' <"keyevent.out.$ZONE.test$n" | tail -1)
else
# inline-signing zone adds "(signed)"
- _time=$(awk '{print $10}' <"keyevent.out.$ZONE.test$n" | tail -1)
+ _time=$(awk '{print $9}' <"keyevent.out.$ZONE.test$n" | tail -1)
fi
# The next key event time must within threshold of the
ret=0
# convert the hexadecimal key from the TAT query into decimal and
# compare against the known key.
-tathex=$(grep "query '_ta-[0-9a-f][0-9a-f]*/NULL/IN' approved" ns1/named.run | awk '{print $6; exit 0}' | sed -e 's/(_ta-\([0-9a-f][0-9a-f]*\)):/\1/') || true
+tathex=$(grep "query '_ta-[0-9a-f][0-9a-f]*/NULL/IN' approved" ns1/named.run | awk '{print $5; exit 0}' | sed -e 's/(_ta-\([0-9a-f][0-9a-f]*\)):/\1/') || true
tatkey=$($PERL -e 'printf("%d\n", hex(@ARGV[0]));' "$tathex")
realkey=$(rndccmd 10.53.0.2 secroots - | sed -n "s#.*${DEFAULT_ALGORITHM}/\([0-9][0-9]*\) ; .*managed.*#\1#p")
[ "$tatkey" -eq "$realkey" ] || ret=1
test_start "checking startup notify rate limit"
awk '/x[0-9].*sending notify to/ {
- split($2, a, ":");
+ split($1, ts, "T");
+ split(ts[2], a, ":");
this = a[1] * 3600 + a[2] * 60 + a[3];
if (lasta1 && lasta1 > a[1]) {
fix = 3600 * 24;
# the shell *ought* to have created the file immediately, but this
# logic allows the creation to be delayed without issues
if (open(my $fh, "<", $runfile)) {
- # the two non-whitespace blobs should be the date and time
+ # the whitespace blob should be an ISO timestamp
# but we don't care about them really, only that they are there
- return scalar(grep /^\S+ \S+ running\R/, <$fh>);
+ return scalar(grep /^\S+[ T]\S+ running\R/, <$fh>);
} else {
return 0;
}
sleep 10
# there may be multiple log entries so get the last one.
-expire=$(awk '/edns-expire\/IN: got EDNS EXPIRE of/ { x=$9 } END { print x }' ns7/named.run)
+expire=$(awk '/edns-expire\/IN: got EDNS EXPIRE of/ { x=$8 } END { print x }' ns7/named.run)
test ${expire:-0} -gt 0 -a ${expire:-0} -lt 1814400 || {
echo_i "failed (expire=${expire:-0})"
status=$((status + 1))
:short: Specifies the time format for log messages.
:any:`print-time` can be set to ``yes``, ``no``, or a time format
- specifier, which may be one of ``local``, ``iso8601``, or
- ``iso8601-utc``. If set to ``no``, the date and time are not
- logged. If set to ``yes`` or ``local``, the date and time are logged in
- a human-readable format, using the local time zone. If set to
- ``iso8601``, the local time is logged in ISO 8601 format. If set to
+ specifier, which may be one of ``local``, ``iso8601``, ``iso8601-utc``
+ or ``iso8601-tzinfo``. If set to ``no``, the date and time are
+ not logged. If set to ``yes`` or ``local``, the date and time are
+ logged in a human-readable format, using the local time zone. If
+ set to ``iso8601``, the local time is logged in ISO 8601 format,
+ but no timezone information is included in the timestamp. If set to
``iso8601-utc``, the date and time are logged in ISO 8601 format,
- with time zone set to UTC. The default is ``no``.
+ with time zone set to UTC. If set to ``iso8601-tzinfo``, the local
+ time is logged in ISO 8601 format, with timezone information included
+ at the end of the timestamp. The default is ``no``.
:any:`print-time` may be specified for a :any:`syslog` channel, but it is
usually pointless since :any:`syslog` also logs the date and time.
null;
print-category <boolean>;
print-severity <boolean>;
- print-time ( iso8601 | iso8601-utc | local | <boolean> );
+ print-time ( iso8601 | iso8601-utc | iso8601-tzinfo | local | <boolean> );
severity <log_severity>;
stderr;
syslog [ <syslog_facility> ];
#define ISC_LOG_OPENERR 0x08000 /* internal */
#define ISC_LOG_ISO8601 0x10000 /* if PRINTTIME, use ISO8601 */
#define ISC_LOG_UTC 0x20000 /* if PRINTTIME, use UTC */
+#define ISC_LOG_TZINFO 0x40000 /* if PRINTTIME, output TZ info */
/*@}*/
/*@{*/
*\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);
/*%<
*/
void
-isc_time_formatISO8601Lus(const isc_time_t *t, char *buf, unsigned int len);
+isc_time_formatISO8601TZms(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.ssssss"
+ * using the ISO8601 format: "yyyy-mm-ddThh:mm:ss.sss+hhmm"
* If the text does not fit in the buffer, the result is indeterminate,
* but is always guaranteed to be null terminated.
*
isc_mem_t *mctx;
unsigned int permitted = ISC_LOG_PRINTALL | ISC_LOG_DEBUGONLY |
ISC_LOG_BUFFERED | ISC_LOG_ISO8601 |
- ISC_LOG_UTC;
+ ISC_LOG_UTC | ISC_LOG_TZINFO;
REQUIRE(VALID_CONFIG(lcfg));
REQUIRE(name != NULL);
REQUIRE(destination != NULL || type == ISC_LOG_TONULL);
REQUIRE(level >= ISC_LOG_CRITICAL);
REQUIRE((flags & ~permitted) == 0);
+ REQUIRE(!(flags & ISC_LOG_UTC) || !(flags & ISC_LOG_TZINFO));
/* FIXME: find duplicate names? */
const char *format, va_list args) {
int syslog_level;
const char *time_string;
- char local_time[64];
- char iso8601z_string[64];
- char iso8601l_string[64];
+ char local_time[64] = { 0 };
+ char iso8601z_string[64] = { 0 };
+ char iso8601l_string[64] = { 0 };
+ char iso8601tz_string[64] = { 0 };
char level_string[24] = { 0 };
struct stat statbuf;
bool matched = false;
- bool printtime, iso8601, utc, printtag, printcolon;
+ bool printtime, iso8601, utc, tzinfo, printtag, printcolon;
bool printcategory, printmodule, printlevel, buffered;
isc_logchannel_t *channel;
isc_logchannellist_t *category_channels;
return;
}
- local_time[0] = '\0';
- iso8601l_string[0] = '\0';
- iso8601z_string[0] = '\0';
-
rcu_read_lock();
LOCK(&isc__lctx->lock);
sizeof(iso8601z_string));
isc_time_formatISO8601Lms(&isctime, iso8601l_string,
sizeof(iso8601l_string));
+ isc_time_formatISO8601TZms(&isctime, iso8601tz_string,
+ sizeof(iso8601tz_string));
}
if ((channel->flags & ISC_LOG_PRINTLEVEL) != 0 &&
}
utc = ((channel->flags & ISC_LOG_UTC) != 0);
+ tzinfo = ((channel->flags & ISC_LOG_TZINFO) != 0);
iso8601 = ((channel->flags & ISC_LOG_ISO8601) != 0);
printtime = ((channel->flags & ISC_LOG_PRINTTIME) != 0);
printtag = ((channel->flags &
if (iso8601) {
if (utc) {
time_string = iso8601z_string;
+ } else if (tzinfo) {
+ time_string = iso8601tz_string;
} else {
time_string = iso8601l_string;
}
return (ISC_R_SUCCESS);
}
-void
-isc_time_formatISO8601L(const isc_time_t *t, char *buf, unsigned int len) {
- time_t now;
- unsigned int flen;
- struct tm tm;
-
- REQUIRE(t != NULL);
- INSIST(t->nanoseconds < NS_PER_SEC);
- REQUIRE(buf != NULL);
- REQUIRE(len > 0);
-
- now = (time_t)t->seconds;
- flen = strftime(buf, len, "%Y-%m-%dT%H:%M:%S", localtime_r(&now, &tm));
- INSIST(flen < len);
-}
-
void
isc_time_formatISO8601Lms(const isc_time_t *t, char *buf, unsigned int len) {
time_t now;
}
void
-isc_time_formatISO8601Lus(const isc_time_t *t, char *buf, unsigned int len) {
+isc_time_formatISO8601TZms(const isc_time_t *t, char *buf, unsigned int len) {
+ char strftime_buf[64] = { 0 };
+ char ms_buf[8] = { 0 };
time_t now;
unsigned int flen;
struct tm tm;
REQUIRE(len > 0);
now = (time_t)t->seconds;
- flen = strftime(buf, len, "%Y-%m-%dT%H:%M:%S", localtime_r(&now, &tm));
+ flen = strftime(strftime_buf, len, "%Y-%m-%dT%H:%M:%S.xxx%z",
+ localtime_r(&now, &tm));
+ snprintf(ms_buf, sizeof(ms_buf), ".%03u", t->nanoseconds / NS_PER_MS);
+
INSIST(flen < len);
- if (flen > 0U && len - flen >= 6) {
- snprintf(buf + flen, len - flen, ".%06u",
- t->nanoseconds / NS_PER_US);
- }
+ size_t local_date_len = sizeof("yyyy-mm-ddThh:mm:ss") - 1ul;
+ size_t ms_date_len = local_date_len + 4;
+
+ memmove(buf, strftime_buf, local_date_len);
+ memmove(buf + local_date_len, ms_buf, 4);
+ memmove(buf + ms_date_len, strftime_buf + ms_date_len, 3);
+ buf[ms_date_len + 3] = ':';
+ memmove(buf + ms_date_len + 4, strftime_buf + ms_date_len + 3, 3);
}
-
void
isc_time_formatISO8601(const isc_time_t *t, char *buf, unsigned int len) {
time_t now;
* - There must exactly one of file/syslog/null/stderr
*/
-static const char *printtime_enums[] = { "iso8601", "iso8601-utc", "local",
- NULL };
+static const char *printtime_enums[] = { "iso8601", "iso8601-utc",
+ "iso8601-tzinfo", "local", NULL };
static isc_result_t
parse_printtime(cfg_parser_t *pctx, const cfg_type_t *type, cfg_obj_t **ret) {
return (cfg_parse_enum_or_other(pctx, type, &cfg_type_boolean, ret));
assert_string_equal(buf, "2015-12-13T09:46:40.123456Z");
}
-/* print local time in ISO8601 */
+/* print local time in ISO8601 with milliseconds and timezone */
-ISC_RUN_TEST_IMPL(isc_time_formatISO8601L_test) {
+ISC_RUN_TEST_IMPL(isc_time_formatISO8601TZms_test) {
isc_time_t t;
char buf[64];
setenv("TZ", "America/Los_Angeles", 1);
t = isc_time_now();
- /* check formatting: yyyy-mm-ddThh:mm:ss */
+ /* check formatting: yyyy-mm-ddThh:mm:ss.sss */
memset(buf, 'X', sizeof(buf));
- isc_time_formatISO8601L(&t, buf, sizeof(buf));
- assert_int_equal(strlen(buf), 19);
+ buf[63] = '\0';
+ isc_time_formatISO8601TZms(&t, buf, sizeof(buf));
+ assert_int_equal(strlen(buf), strlen("yyyy-mm-ddThh:mm:ss.sss+hh:mm"));
+
assert_int_equal(buf[4], '-');
assert_int_equal(buf[7], '-');
assert_int_equal(buf[10], 'T');
assert_int_equal(buf[13], ':');
assert_int_equal(buf[16], ':');
+ assert_int_equal(buf[19], '.');
+
+ size_t plus_minus[2] = { '+', '-' };
+ assert_in_set(buf[23], plus_minus, sizeof(plus_minus));
+ assert_int_equal(buf[26], ':');
/* check time conversion correctness */
memset(buf, 'X', sizeof(buf));
isc_time_settoepoch(&t);
- isc_time_formatISO8601L(&t, buf, sizeof(buf));
- assert_string_equal(buf, "1969-12-31T16:00:00");
+ isc_time_formatISO8601Lms(&t, buf, sizeof(buf));
+ assert_string_equal(buf, "1969-12-31T16:00:00.000");
memset(buf, 'X', sizeof(buf));
isc_time_set(&t, 1450000000, 123000000);
- isc_time_formatISO8601L(&t, buf, sizeof(buf));
- assert_string_equal(buf, "2015-12-13T01:46:40");
+ isc_time_formatISO8601Lms(&t, buf, sizeof(buf));
+ assert_string_equal(buf, "2015-12-13T01:46:40.123");
}
-
/* print local time in ISO8601 with milliseconds */
ISC_RUN_TEST_IMPL(isc_time_formatISO8601Lms_test) {
assert_string_equal(buf, "2015-12-13T01:46:40.123");
}
-/* print local time in ISO8601 with microseconds */
-
-ISC_RUN_TEST_IMPL(isc_time_formatISO8601Lus_test) {
- isc_time_t t;
- char buf[64];
-
- UNUSED(state);
-
- setenv("TZ", "America/Los_Angeles", 1);
- t = isc_time_now_hires();
-
- /* check formatting: yyyy-mm-ddThh:mm:ss.ssssss */
- memset(buf, 'X', sizeof(buf));
- isc_time_formatISO8601Lus(&t, buf, sizeof(buf));
- assert_int_equal(strlen(buf), 26);
- assert_int_equal(buf[4], '-');
- assert_int_equal(buf[7], '-');
- assert_int_equal(buf[10], 'T');
- assert_int_equal(buf[13], ':');
- assert_int_equal(buf[16], ':');
- assert_int_equal(buf[19], '.');
-
- /* check time conversion correctness */
- memset(buf, 'X', sizeof(buf));
- isc_time_settoepoch(&t);
- isc_time_formatISO8601Lus(&t, buf, sizeof(buf));
- assert_string_equal(buf, "1969-12-31T16:00:00.000000");
-
- memset(buf, 'X', sizeof(buf));
- isc_time_set(&t, 1450000000, 123456000);
- isc_time_formatISO8601Lus(&t, buf, sizeof(buf));
- assert_string_equal(buf, "2015-12-13T01:46:40.123456");
-}
-
/* print UTC time as yyyymmddhhmmsssss */
ISC_RUN_TEST_IMPL(isc_time_formatshorttimestamp_test) {
ISC_TEST_ENTRY(isc_time_formatISO8601_test)
ISC_TEST_ENTRY(isc_time_formatISO8601ms_test)
ISC_TEST_ENTRY(isc_time_formatISO8601us_test)
-ISC_TEST_ENTRY(isc_time_formatISO8601L_test)
ISC_TEST_ENTRY(isc_time_formatISO8601Lms_test)
-ISC_TEST_ENTRY(isc_time_formatISO8601Lus_test)
+ISC_TEST_ENTRY(isc_time_formatISO8601TZms_test)
ISC_TEST_ENTRY(isc_time_formatshorttimestamp_test)
ISC_TEST_LIST_END