Download raw body.
httpd: add timestamps to fastcgi error log
Am 01.11.2026 um 20:46 schrieb Rafael Sadowski:
> On Sun Nov 01, 2026 at 08:12:23PM +0100, Claudio Jeker wrote:
>> On Sun, Nov 01, 2026 at 06:59:48PM +0100, Rafael Sadowski wrote:
>>> I don't suppose anyone has ever tried to debug their error logs.
>>
>> I did but I normally have a no other traffic to worry about. Also I only
>> did this live.
>>
>>> This diff changes the log from:
>>>
>>> error.cgi: lab test error, GET /cgi-bin/error.cgi
>>>
>>> to:
>>>
>>> 01/Nov/2026:18:53:55 +0100: error.cgi: lab test error, GET /cgi-bin/error.cgi
>>>
>>> Does anyone have a better idea for a syntax? OK?
>>
>> I prefer ISO format for timestamps like used by syslogd -Z.
Same here.
>> Timestamps are certainly useful for non syslog logging.
>
> Thanks for the feedback, sure. With the diff below, it looks like this:
>
> 2026-11-01T20:40:20: error.cgi: lab test error, GET /cgi-bin/error.cgi
>
> commit cc7e31596c708775558a0b857170bb94fce407d0
> Author: Rafael Sadowski <rafael@sizeofvoid.org>
> Date: Sun Nov 1 15:18:04 2026 +0100
>
> httpd: add timestamps to fastcgi error log
>
> diff --git a/httpd.h b/httpd.h
> index 1e54479..a3f290f 100644
> --- a/httpd.h
> +++ b/httpd.h
> @@ -695,6 +695,7 @@ struct server_config *serverconfig_byid(uint32_t);
> int server_foreach(int (*)(struct server *,
> struct server_config *, void *), void *);
> struct server *server_match(struct server *, int);
> +int server_log_time(char *buf, size_t len, const char *);
>
> SPLAY_PROTOTYPE(client_tree, client, clt_nodes, server_client_cmp);
>
> diff --git a/server.c b/server.c
> index 9975a1c..750e9ca 100644
> --- a/server.c
> +++ b/server.c
> @@ -1541,4 +1541,21 @@ server_client_cmp(struct client *a, struct client *b)
> return ((int)a->clt_id - b->clt_id);
> }
>
> +int
> +server_log_time(char *buf, size_t len, const char *format)
> +{
> + time_t t;
> + struct tm tm;
> +
> + if ((t = time(NULL)) == -1)
> + return (-1);
> + if (localtime_r(&t, &tm) == NULL)
> + return (-1);
> + if (strftime(buf, len,
> + format == NULL ? "%d/%b/%Y:%H:%M:%S %z" : format, &tm) == 0)
^^^^^^^^^^^^^^^^^^^^
This now makes it use two different time formats. See below.
> + return (-1);
> +
> + return (0);
> +}
> +
> SPLAY_GENERATE(client_tree, client, clt_nodes, server_client_cmp);
> diff --git a/server_fcgi.c b/server_fcgi.c
> index 2428adb..64570cd 100644
> --- a/server_fcgi.c
> +++ b/server_fcgi.c
> @@ -85,6 +85,7 @@ int server_fcgi_writechunk(struct client *);
> int server_fcgi_getheaders(struct client *);
> int fcgi_add_param(struct server_fcgi_param *, const char *, const char *,
> struct client *);
> +void server_fcgi_err_log(struct client *);
>
> int
> server_fcgi(struct httpd *env, struct client *clt)
> @@ -512,6 +513,32 @@ server_fcgi_error(struct bufferevent *bev, short error, void *arg)
> server_file_error(bev, error, arg);
> }
>
> +void
> +server_fcgi_err_log(struct client *clt)
> +{
> + char tstamp[33];
> + struct server_config *srv_conf;
> + size_t len;
> + char *msg;
> +
> + if ((srv_conf = clt->clt_srv_conf) == NULL)
> + return;
> +
> + if ((len = EVBUFFER_LENGTH(clt->clt_srvevb)) == 0)
> + return;
> +
> + if ((msg = get_string(EVBUFFER_DATA(clt->clt_srvevb), len)) == NULL)
> + return;
> +
> + if ((srv_conf->flags & SRVFLAG_SYSLOG) == 0 &&
> + server_log_time(tstamp, sizeof(tstamp), "%FT%T") == 0) {
^^^^^^^
> + server_sendlog(srv_conf, IMSG_LOG_ERROR, "%s: %s", tstamp, msg);
> + } else {
> + server_sendlog(srv_conf, IMSG_LOG_ERROR, "%s", msg);
> + }
> + free(msg);
> +}
> +
> void
> server_fcgi_read(struct bufferevent *bev, void *arg)
> {
> @@ -519,7 +546,6 @@ server_fcgi_read(struct bufferevent *bev, void *arg)
> struct client *clt = (struct client *)arg;
> struct fcgi_record_header *h;
> size_t len;
> - char *ptr;
>
> do {
> len = bufferevent_read(bev, buf, clt->clt_fcgi.toread);
> @@ -561,15 +587,7 @@ server_fcgi_read(struct bufferevent *bev, void *arg)
> case FCGI_READ_CONTENT:
> switch (clt->clt_fcgi.type) {
> case FCGI_STDERR:
> - if (EVBUFFER_LENGTH(clt->clt_srvevb) > 0 &&
> - (ptr = get_string(
> - EVBUFFER_DATA(clt->clt_srvevb),
> - EVBUFFER_LENGTH(clt->clt_srvevb))) !=
> - NULL) {
> - server_sendlog(clt->clt_srv_conf,
> - IMSG_LOG_ERROR, "%s", ptr);
> - free(ptr);
> - }
> + server_fcgi_err_log(clt);
> break;
> case FCGI_STDOUT:
> ++clt->clt_chunk;
> diff --git a/server_http.c b/server_http.c
> index 2c4bb74..bc7e90c 100644
> --- a/server_http.c
> +++ b/server_http.c
> @@ -2042,13 +2042,11 @@ replace_var(char *str, const char *var, const char *repl)
> int
> server_log_http(struct client *clt, unsigned int code, size_t len)
> {
> - static char tstamp[64];
> static char ip[INET6_ADDRSTRLEN];
> - time_t t;
> struct kv key, *agent, *referrer, *xff, *xfp;
> - struct tm *tm;
> struct server_config *srv_conf;
> struct http_descriptor *desc;
> + char tstamp[64];
> int ret = -1;
> char *user = NULL;
> char *path = NULL;
> @@ -2065,11 +2063,7 @@ server_log_http(struct client *clt, unsigned int code, size_t len)
> if ((desc = clt->clt_descreq) == NULL)
> return (-1);
>
> - if ((t = time(NULL)) == -1)
> - return (-1);
> - if ((tm = localtime(&t)) == NULL)
> - return (-1);
> - if (strftime(tstamp, sizeof(tstamp), "%d/%b/%Y:%H:%M:%S %z", tm) == 0)
> + if (server_log_time(tstamp, sizeof(tstamp), NULL) == -1)
^^^^
> return (-1);
>
> if (print_host(&clt->clt_ss, ip, sizeof(ip)) == NULL)
Syslog looks like this on OpenBSD: 2026-11-02T07:01:38+01:00 .....
On a Debian Trixie box it will include fractional seconds:
2026-11-02T07:02:34.477794+01:00 ....
If it is option to give up on the old format and use the same format
syslog is using I'd go for that.
Apache access log looks like this [02/Nov/2026:07:04:24 +0100], though.
The abbreviated month name is even locale dependent so if changing the
format would break certain programs parsing that log, parsing will just
get easier but needs updateing. Not sure.
Regards,
--
Christian
httpd: add timestamps to fastcgi error log