Core: add RFC 5424 syslog millisecond-accurate timestamp.

Remove the per-second cached_syslog_rfc5424_time slot array that was
added in the previous commit.  The cached approach would populate the
millisecond field with the value at second rollover (usually near 0),
defeating the sub-second precision that RFC 5424 was requested for.

Instead, in ngx_syslog_add_header(), build the RFC 5424 TIMESTAMP
field inline:

  - The date, time, and UTC offset are read from
    ngx_cached_http_log_iso8601 ("YYYY-MM-DDTHH:MM:SS±HH:MM"),
    splitting the 25-byte string at position 19.
  - The millisecond sub-field is taken from ngx_timeofday()->msec,
    which is updated on every event-loop tick by ngx_time_update().

This produces timestamps accurate to the resolution of the event
loop (typically 1 ms) at negligible per-message cost.
This commit is contained in:
Vadim Zhestikov 2026-03-25 10:37:35 -07:00
parent 366d275785
commit d92ee133cf
3 changed files with 33 additions and 37 deletions

View file

@ -11,7 +11,7 @@
#define NGX_SYSLOG_MAX_STR \
NGX_MAX_ERROR_STR + sizeof("<255>1 ") - 1 \
+ sizeof("1970-09-28T12:00:00.000+06:00") - 1 + 1 /* space */ \
+ sizeof("1970-09-28T12:00:00.000+06:00") - 1 + 1 /* space */ \
+ (NGX_MAXHOSTNAMELEN - 1) + 1 /* space */ \
+ 48 /* APP-NAME/TAG */ + 1 /* space */ \
+ NGX_INT64_LEN /* PROCID */ + sizeof(" - - ") - 1
@ -302,7 +302,9 @@ ngx_syslog_parse_args(ngx_conf_t *cf, ngx_syslog_peer_t *peer)
u_char *
ngx_syslog_add_header(ngx_syslog_peer_t *peer, u_char *buf)
{
ngx_uint_t pri;
ngx_uint_t pri;
ngx_str_t datetime, tz;
ngx_time_t *tp;
pri = peer->facility * 8 + peer->severity;
@ -312,18 +314,39 @@ ngx_syslog_add_header(ngx_syslog_peer_t *peer, u_char *buf)
* RFC 5424 HEADER: VERSION SP TIMESTAMP SP HOSTNAME SP
* APP-NAME SP PROCID SP MSGID SP STRUCTURED-DATA SP
*
* PROCID is set to the nginx process PID. MSGID and
* STRUCTURED-DATA are set to the nil value "-".
* TIMESTAMP is formatted as an ISO 8601 date-time with
* millisecond precision and UTC offset, e.g.:
* 2003-10-11T22:14:15.003+05:30
*
* The date, time, and UTC offset are taken from the
* ngx_cached_http_log_iso8601 cache ("YYYY-MM-DDTHH:MM:SS±HH:MM",
* 25 bytes). The first 19 bytes are "YYYY-MM-DDTHH:MM:SS"
* and the trailing 6 bytes are "±HH:MM". The millisecond
* field is read live from ngx_timeofday() so that it reflects
* the current event-loop tick rather than the start of the
* current second.
*
* PROCID is the nginx process PID. MSGID and STRUCTURED-DATA
* are set to the nil value "-".
*/
tp = ngx_timeofday();
datetime.data = ngx_cached_http_log_iso8601.data;
datetime.len = sizeof("1970-09-28T12:00:00") - 1;
tz.data = ngx_cached_http_log_iso8601.data
+ sizeof("1970-09-28T12:00:00") - 1;
tz.len = sizeof("+06:00") - 1;
if (peer->nohostname) {
return ngx_sprintf(buf, "<%ui>1 %V - %V %P - - ",
pri, &ngx_cached_syslog_rfc5424_time,
return ngx_sprintf(buf, "<%ui>1 %V.%03ui%V - %V %P - - ",
pri, &datetime, tp->msec, &tz,
&peer->tag, ngx_pid);
}
return ngx_sprintf(buf, "<%ui>1 %V %V %V %P - - ",
pri, &ngx_cached_syslog_rfc5424_time,
return ngx_sprintf(buf, "<%ui>1 %V.%03ui%V %V %V %P - - ",
pri, &datetime, tp->msec, &tz,
peer->hostname, &peer->tag, ngx_pid);
}

View file

@ -33,7 +33,6 @@ volatile ngx_str_t ngx_cached_http_time;
volatile ngx_str_t ngx_cached_http_log_time;
volatile ngx_str_t ngx_cached_http_log_iso8601;
volatile ngx_str_t ngx_cached_syslog_time;
volatile ngx_str_t ngx_cached_syslog_rfc5424_time;
#if !(NGX_WIN32)
@ -57,8 +56,6 @@ static u_char cached_http_log_iso8601[NGX_TIME_SLOTS]
[sizeof("1970-09-28T12:00:00+06:00")];
static u_char cached_syslog_time[NGX_TIME_SLOTS]
[sizeof("Sep 28 12:00:00")];
static u_char cached_syslog_rfc5424_time[NGX_TIME_SLOTS]
[sizeof("1970-09-28T12:00:00.000+06:00")];
static char *week[] = { "Sun", "Mon", "Tue", "Wed", "Thu", "Fri", "Sat" };
@ -73,8 +70,6 @@ ngx_time_init(void)
ngx_cached_http_log_time.len = sizeof("28/Sep/1970:12:00:00 +0600") - 1;
ngx_cached_http_log_iso8601.len = sizeof("1970-09-28T12:00:00+06:00") - 1;
ngx_cached_syslog_time.len = sizeof("Sep 28 12:00:00") - 1;
ngx_cached_syslog_rfc5424_time.len =
sizeof("1970-09-28T12:00:00.000+06:00") - 1;
ngx_cached_time = &cached_time[0];
@ -85,7 +80,7 @@ ngx_time_init(void)
void
ngx_time_update(void)
{
u_char *p0, *p1, *p2, *p3, *p4, *p5;
u_char *p0, *p1, *p2, *p3, *p4;
ngx_tm_t tm, gmt;
time_t sec;
ngx_uint_t msec;
@ -184,15 +179,6 @@ ngx_time_update(void)
months[tm.ngx_tm_mon - 1], tm.ngx_tm_mday,
tm.ngx_tm_hour, tm.ngx_tm_min, tm.ngx_tm_sec);
p5 = &cached_syslog_rfc5424_time[slot][0];
(void) ngx_sprintf(p5, "%4d-%02d-%02dT%02d:%02d:%02d.%03ui%c%02i:%02i",
tm.ngx_tm_year, tm.ngx_tm_mon,
tm.ngx_tm_mday, tm.ngx_tm_hour,
tm.ngx_tm_min, tm.ngx_tm_sec, msec,
tp->gmtoff < 0 ? '-' : '+',
ngx_abs(tp->gmtoff / 60), ngx_abs(tp->gmtoff % 60));
ngx_memory_barrier();
ngx_cached_time = tp;
@ -201,7 +187,6 @@ ngx_time_update(void)
ngx_cached_http_log_time.data = p2;
ngx_cached_http_log_iso8601.data = p3;
ngx_cached_syslog_time.data = p4;
ngx_cached_syslog_rfc5424_time.data = p5;
ngx_unlock(&ngx_time_lock);
}
@ -229,7 +214,7 @@ ngx_monotonic_time(time_t sec, ngx_uint_t msec)
void
ngx_time_sigsafe_update(void)
{
u_char *p, *p2, *p3;
u_char *p, *p2;
ngx_tm_t tm;
time_t sec;
ngx_time_t *tp;
@ -275,21 +260,10 @@ ngx_time_sigsafe_update(void)
months[tm.ngx_tm_mon - 1], tm.ngx_tm_mday,
tm.ngx_tm_hour, tm.ngx_tm_min, tm.ngx_tm_sec);
p3 = &cached_syslog_rfc5424_time[slot][0];
(void) ngx_sprintf(p3, "%4d-%02d-%02dT%02d:%02d:%02d.000%c%02i:%02i",
tm.ngx_tm_year, tm.ngx_tm_mon,
tm.ngx_tm_mday, tm.ngx_tm_hour,
tm.ngx_tm_min, tm.ngx_tm_sec,
cached_gmtoff < 0 ? '-' : '+',
ngx_abs(cached_gmtoff / 60),
ngx_abs(cached_gmtoff % 60));
ngx_memory_barrier();
ngx_cached_err_log_time.data = p;
ngx_cached_syslog_time.data = p2;
ngx_cached_syslog_rfc5424_time.data = p3;
ngx_unlock(&ngx_time_lock);
}

View file

@ -41,7 +41,6 @@ extern volatile ngx_str_t ngx_cached_http_time;
extern volatile ngx_str_t ngx_cached_http_log_time;
extern volatile ngx_str_t ngx_cached_http_log_iso8601;
extern volatile ngx_str_t ngx_cached_syslog_time;
extern volatile ngx_str_t ngx_cached_syslog_rfc5424_time;
/*
* milliseconds elapsed since some unspecified point in the past