search

mbrubeck / agate

Very simple server for the Gemini hypertext protocol
Apache License 2.0
610 stars 37 forks source link

Logging to stdout and stderr #277

Closed michaelnordmeyer closed 2 months ago

michaelnordmeyer commented 1 year ago

I use Agate with systemd, so all logging goes by default to the journal. Because not only resource access logging goes into the journal, it interferes with parsing the log. Example output:

Started agate.service - Agate Gemini Server.
[2023-07-31T14:28:10Z WARN  agate] Could not start listener on 0.0.0.0:1965, but already listening on another unspecified address. Probably your system automatically listens in dual stack?
[2023-07-31T14:28:10Z INFO  agate] Started listener on [::]:1965
[2023-07-31T14:33:16Z INFO  agate] [::ffff:4.3.2.1]:1965 ::ffff:1.2.3.4 "gemini://example.com/" 20 "text/gemini"
Stopping agate.service - Agate Gemini Server...
agate.service: Deactivated successfully.
Stopped agate.service - Agate Gemini Server.

If I switch my systemd's agate.service to

StandardOutput=append:/var/log/agate/access.log
StandardError=append:/var/log/agate/error.log

which mimics the way nginx is logging and use ordinary log files, then all logging goes to error.log, because Agate currently logs to stderr and not stdout. If I change the env_logger to log to stdout, then all logging goes to access.log. It looks like this:

Journal

Started agate.service - Agate Gemini Server.
Stopping agate.service - Agate Gemini Server...
agate.service: Deactivated successfully.
Stopped agate.service - Agate Gemini Server.

Access.log

[2023-07-31T14:28:10Z WARN  agate] Could not start listener on 0.0.0.0:1965, but already listening on another unspecified address. Probably your system automatically listens in dual stack?
[2023-07-31T14:28:10Z INFO  agate] Started listener on [::]:1965
[2023-07-31T14:33:16Z INFO  agate] [::ffff:4.3.2.1]:1965 ::ffff:1.2.3.4 "gemini://example.com/" 20 "text/gemini"

Error.log

<empty>

What I would like to have is only user-generated, uniform log lines in access.log so I can parse them properly:

Access.log

[2023-07-31T14:33:16Z INFO  agate] [::ffff:4.3.2.1]:1965 ::ffff:1.2.3.4 "gemini://example.com/" 20 "text/gemini"

Error.log

[2023-07-31T14:28:10Z WARN  agate] Could not start listener on 0.0.0.0:1965, but already listening on another unspecified address. Probably your system automatically listens in dual stack?
[2023-07-31T14:28:10Z INFO  agate] Started listener on [::]:1965

I'm not a Rust expert, but I don't see anything in env_logger, which could achieve this, except using two different loggers, one for stdout and one for stderr.

Any ideas or opinions?

michaelnordmeyer commented 1 year ago

BTW, the current one log solution already led to Agate introducing two non-spec status codes, 00 TLS error and 01 IP error, to be able to log those error scenarios to the log file (see https://github.com/mbrubeck/agate#logging).