customize log verbosity

[ilkosta]

Hi,
Postgrest seems fantastic!
It would be nice to see logged near the requests submitted to postgrest, also the pg response errors.
What do you think?

[begriffs]

We could add that, although the errors will be in your db logs as well depending on your logging settings.

[begriffs]

Note there is more documentation now about debugging server problems - https://postgrest.readthedocs.io/en/v0.4/admin.html#debugging

[begriffs]

Revisiting this, a log level would be nice in order to both reduce logging (since it might be duplicating the logs of a proxy server), or turn them up.

I propose we allow syslog style log levels.

[trourance]

Hi, are there any progress on that ?
All other tickets end up here. I would like to have some verbose logging without having to modify the db side logs, for example for SSL connection:
SSL established: TLSv1.2/ECDHE-RSA-AES256-GCM-SHA384/ECDH=prime256v1

[steve-chavez]

When having several clients that access the database, it can be hard to pinpoint the log entries that belong to a particular pgrst instance.

I think we should recommend using log_line_prefix and setting application_name in the connection uri(on db-uri). This would be like:

postgres://user@localhost/mydb?application_name=pgrst_mydb_myschema"

I was also thinking if we could somehow set the application_name ourselves. But in any case this should be documented.

[steve-chavez]

I have a counterpoint against doing more detailed logging in the syslog style.

Recently, I helped an user that was in need of an audit trail for PostgREST events, this was needed for compliance with a standard. The idea was to have detailed request information in JSON(payload body, headers, success/error codes, etc) and then send them to Kafka for later processing.

Naturally the first idea that comes to mind was to add more detailed logging in PostgREST itself and construct the required JSON.

However, this detailed logging would introduce code paths that can lead to performance degradation. In the past we have had problems such as #690 and #925(#1206 still open btw). Those were fixed basically by not messing with the payload body in Haskell code and instead rely on directly sending it to pg through parametrized queries.

So, why introduce these issues in PostgREST(we'd have to discuss what goes in a DEBUG level, which format, measure the memory consumption impact, go back to previous perf issues for certain settings, etc) when PostgreSQL logs can already be formatted in JSON(thanks to jsonlog, this was the eventual solution we landed on) with much more detailed information than what we could output in pgrst(certain error messages will not be exposed through libpq, see nikita-volkov/hasql#112).

CSV logs are also already available in pg and jsonlog could soon be included in core(see this discussion).

I think PostgREST has remained and should still be a transparent layer over PostgreSQL. We could leave the detailed logging to PostgreSQL. In a way this would also reinforce our "db as the source of truth" principle.

I propose we refrain from detailed logging and to always do minimal logging(not go to a higher level). Instead we should add to the docs a good explanation on logging with these recommendations #540 (comment) (we can include some log samples) and with a single grep pgrst_mydb_myschema one can get all the detailed logging pg already provides for your pgrst instance(to debug SSL issues, etc).

[steve-chavez]

A bit unrelated, but we could provide an option for error responses verbosity. Some users might not want to expose the full {"message": "permission denied..", "hint": ".."} .

I've noted that we do SET client_min_messages TO WARNING; for each transaction, perhaps we can do this at the libpq level and set this client_min_messages to a lower level and devoid the messages.

[steve-chavez]

For docs, we could also show how to set the log_min_messages per postgrest app. By recommending to set the setting per user(can also be done per db but probably not desired), like: alter role authenticator set log_min_messages to fatal.

[steve-chavez]

A lower level of logging - for failed requests(status >=400):

• Can be done by using https://hackage.haskell.org/package/wai-extra-3.0.29.2/docs/Network-Wai-Middleware-RequestLogger.html#t:RequestLoggerSettings in Middleware.hs.
• Example of how to use this: https://stackoverflow.com/a/25538767/4692662

Edit:

Actually I'm not sure how to do this with the above interface. WAI is looking too low level.

We might have to check how Yesod uses WAI to do logging levels:

http://hackage.haskell.org/package/yesod-core-1.1.8.3/docs/Yesod-Core.html#v:LevelDebug

[ghost]

another to options for the record:

• if log is too verbose on clientside eat it in nginx: [HOWTO hardening] Replace error messages in nginx postgrest-docs#326
• if systemd started postgrest is too verbose reroute it via StandardOutput= etc

[steve-chavez]

One more reason to offer a lower log level, the verbose output makes the log file grow quickly.

Also, one other thing I've noticed is that our connection retries messages go to stdout. They should go to stderr.

So, looks like we should have a logging_level config option that offers three levels:

• info: Our current logging level. Log all requests, successful or unsuccessful.
• debug: In addition to logging all requests. Show the main SQL query. No parameters from prepared statements will show.
• error: Only log unsuccessful requests.

Should error be the default level? Maybe we should make a breaking change now.

[trourance]

+1 to set error as the default level.

[steve-chavez]

log-level config added! #1604

Also, the error level is now the default.

I'll close this general issue and continue to track the debug level on #1578.