search

shlinkio / shlink

The definitive self-hosted URL shortener
https://shlink.io
MIT License
2.97k stars 249 forks source link

v3.7.0 logging "DEBUG server req-resp mode" #1934

Closed frankfil closed 7 months ago

frankfil commented 7 months ago

Shlink version

3.7.0

PHP version

8.2.12

How do you serve Shlink

RoadRunner Docker image

Database engine

MySQL

Database version

5.7

Current behavior

After upgrading from v3.4.0 to v3.7.0 we are seeing the following log entries every 10 seconds, which matches the timing of the health checks being performed by Kubernetes (assuming this is the reason of course):

2023-11-28T00:22:03+0000    DEBUG   server          req-resp mode   {"pid": 40}
2023-11-28T00:22:13+0000    DEBUG   server          req-resp mode   {"pid": 41}
2023-11-28T00:22:23+0000    DEBUG   server          req-resp mode   {"pid": 42}
2023-11-28T00:22:33+0000    DEBUG   server          req-resp mode   {"pid": 43}

Looking at the RoadRunner config in the container config/roadrunner/.rr.yml and it appears that some type of logging debug level is enabled:

logs:
  mode: production
  channels:
    http:
      mode: 'off' # Disable logging as Shlink handles it internally
    server:
      level: debug # Everything written to worker stderr is logged

Should this debug logging level be enabled?

And if this is the cause of the debug logs, can we disable it?

Expected behavior

Health check calls are no longer logged, which is correct but something else is being logged instead.

How to reproduce

Deploy shlinkio/shlink:3.7.0-non-root and perform HTTP calls to /rest/health.

acelaya commented 7 months ago

Please, try not to report a bug for something which actually has no impact on Shlink normal behavior.

When you need to understand an underlying aspect of the service, open a discussion instead.

RoundRunner logging is a bit confusing and it's been hard to get it right. These lines seem to be logged for every request? It's hard to tell.

Setting server log level to debug is what used to be recommended by the docs (in fact I think that config was automatically generated with that value), otherwise there were important information missing. But it seems to be logging too much information now.

I'll try to fine tune the config to see if it improves.