skarnet / s6

The s6 supervision suite.
https://skarnet.org/software/s6/
ISC License
777 stars 35 forks source link

adding hostname in s6-socklog lines and date repetition in s6-log #32

Closed eburghar closed 2 years ago

eburghar commented 2 years ago

Hi,

I certainly missing something, but when using postfix with s6-socklog (using the s6-overlay syslogd addon), I end up having the date duplicated in every log lines. As far as I understood posfix doesn't log any date.

I ended up using S6_LOGGING_SCRIPT='n20 s1000000' and thus removing the T parameter, but this means that s6-log and s6-socklog are both logging timestamps. I wonder if this is normal.

Also, is there a way to add a server name in the log line (to be compatible with postfix log parser), to have something like

Aug 26 11:19:05 smtp postfix/postfix-script[25430]: refreshing the Postfix mail system

instead of

Aug 26 11:19:05 postfix/postfix-script[25430]: refreshing the Postfix mail system

Best regards

skarnet commented 2 years ago

I certainly missing something, but when using postfix with s6-socklog (using the s6-overlay syslogd addon), I end up having the date duplicated in every log lines. As far as I understood posfix doesn't log any date.

You're not missing anything, indeed there's date duplication. The thing is, the syslog() function (both in musl and glibc) prepends every log line with an ISO date, and it's not deactivatable or configurable. I had forgotten this, so I had made the syslogd-log service add a timestamp by default, but it is useless. I have removed the default timestamp in the current git, so you won't have to manually modify S6_LOGGING_SCRIPT once the next version is released.

Also, is there a way to add a server name in the log line (to be compatible with postfix log parser), to have something like

Aug 26 11:19:05 smtp postfix/postfix-script[25430]: refreshing the Postfix mail system

instead of

Aug 26 11:19:05 postfix/postfix-script[25430]: refreshing the Postfix mail system

Unfortunately, it's not possible. syslog() is a global service: it's impossible for syslogd to treat logs lines differently depending on what process sends them. With most syslog implementations, it is even impossible for syslogd to identify the process that sent a log line. If postfix sends a line starting with postfix/postfix-script, syslogd cannot rewrite it into smtp postfix/postfix-script, unless it prepends every log line with smtp.

eburghar commented 2 years ago

Thanks for the explanation.

I think that the hostname is part of the syslog protocol message and is normally received by s6-syslogd. I just thought that for whatever reason (configuration, simplification, ...), it didn't write it to the log line. It was the only reason I saw for the hostname not appearing in the log line as it appears with other syslogd daemon.

skarnet commented 2 years ago

So smtp is your hostname? It is possible that other implementations of syslogd are configured by default to prepend their log lines with the hostname, but that would surprise me because apparently the hostname is inserted after the date. The syslog() protocol definitely does not include the hostname as part of the line. That's weird.

eburghar commented 2 years ago

Sorry I misread the rfc. I quickly look at socklog code and it just parses pri in non raw mode and forward the remaining of the syslog string.

So it's postfix which is sending the date and the hostname ? I don't understand why it writes correctly the hostname with postfix maillog_file parameter and not in syslog mode with socklog.

skarnet commented 2 years ago

Yes, that's what I've been saying. If there's a discrepancy, it's client-side. What you see in the syslogd logs is exactly what the client sent, except for the date.

eburghar commented 2 years ago

Thanks for your time and valuable explanations !