From: Claudio Jeker <cjeker@diehard.n-r-g.com>
Subject: Re: httpd: add timestamps to fastcgi error log
To: Rafael Sadowski <rafael@sizeofvoid.org>
Cc: tech@openbsd.org
Date: Sun, 1 Nov 2026 20:12:23 +0100

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.
Timestamps are certainly useful for non syslog logging.
 
> Rafael
> 
> commit 137ae5a8eb43254b31e20ab8176ea3eb41cfb828
> 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..c7d270d 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);
>  
>  SPLAY_PROTOTYPE(client_tree, client, clt_nodes, server_client_cmp);
>  
> diff --git a/server.c b/server.c
> index 9975a1c..1133666 100644
> --- a/server.c
> +++ b/server.c
> @@ -1541,4 +1541,20 @@ 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)
> +{
> +	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, "%d/%b/%Y:%H:%M:%S %z", &tm) == 0)
> +		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..06a2eb8 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[64];
> +	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)) == 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..bcead3f 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)) == -1)
>  		return (-1);
>  
>  	if (print_host(&clt->clt_ss, ip, sizeof(ip)) == NULL)
> 

-- 
:wq Claudio