In tracelog, skip logging context.Canceled unless debug logging is on

[henvic]

Hi,

The team I am working with is ending up with a lot of 'Acquired' messages in our log that comes from using tracelog due to 'context canceled'. While filtering is easy, it adds unnecessary pressure to the logs and then we're disabling tracelog for the moment because of that.

We imagine other people might face a similar situation. Would it make sense to change the logic of tracelog so that it logs Acquired due to context canceled (that will happen a lot, in our case at least, when a request from a client is cancelled at the client side - for example, on a HTTP request) if the debug mode is on, and silently ignore it if the log level is set to error?

I'm sending some changes that shows an attempt to do that / tentatively tries to solve it adding some filtering to the logic, but I haven't really experimented with this thoroughly yet. Any thoughts about this strategy?

Thank you!

[jackc]

A few thoughts:

This particular change introduces an inconsistency with how context.Canceled is handled. If the cancellation happens during Acquire one thing happens, but if it happens a split second later and the query has been sent then something else happens.

Would it make more sense to add the filtering to the tracelog.Logger? That would be a single place to add filtering and wouldn't require changes to the tracelog package itself.

Would it make sense to vendor and change your own version of tracelog? It's a fairly simple package.

[Radrik5]

Would it make more sense to add the filtering to the tracelog.Logger? That would be a single place to add filtering and wouldn't require changes to the tracelog package itself.

That's a good idea but tracelog.Logger doesn't know about the error:

// Logger is the interface used to get log output from pgx.
type Logger interface {
	// Log a message at the given level with data key/value pairs. data may be nil.
	Log(ctx context.Context, level LogLevel, msg string, data map[string]any)
}

We can work around it with ctx but it looks weird:

func (l *Logger) Log(ctx context.Context, level tracelog.LogLevel, msg string, data map[string]interface{}) {
	if level == tracelog.LogLevelError && errors.Is(ctx.Err(), context.Canceled) {
		level = tracelog.LogLevelInfo
	}