chore(zipkin) Add zipkin prefix to timer logs

[dcarley]

Summary

These run on a timer so they don't get the namespace automatically appended to the log line which makes it hard to determine which plugin they come from:

[error] 1099#0: *436751 [kong] handler.lua:102 reporter flush failed to request: operation timed out, context: ngx.timer, client: 172.17.0.1, server: 0.0.0.0:8443

I've tried looking for a way to solve this generically that would benefit other plugins like rate-limiting but can't see a way to set the logger or get access to the plugin name when the timer is running.

I've omitted the square brackets from zipkin to make it clearer that it's not coming from the automatic namespace formatting.

Full changelog

• feat(zipkin) Add zipkin prefix to timer logs

Issue reference

N/A

Other notes

I'm open to suggestions about how this could be solved generically in a way that would benefit all plugins.

This PR depends on the tests from #8735. I can't see a way to change the base branch, so it will need rebasing after that PR is merged.

[mayocream]

The changes should go to chore instead of feat, and I think this small change is unnecessary to be included in the changelog.

[dcarley]

Sorry for the delay. I've rebased against master, changed the commit to chore, and removed the CHANGELOG entry.

[Tieske]

Shouldn't we be fixing the underlying problem with kong.log to also provide the proper namespace when in a timer context?

@kikito any opinions? iirc you were involved when kong.log was first implemented.

[dcarley]

Shouldn't we be fixing the underlying problem with kong.log to also provide the proper namespace when in a timer context?

I'd love to, but can't see a way to set the logger or get access to the plugin name when the timer is running. The only option I can think of is to provide a wrapper over ngx.timer.at that sets the logger, but even then there's no guarantee that every plugin will use it. Any other ideas?

[Tieske]

@ADD-SP is this something we can fix with the timer-ng lib?

[kikito]

The prefix is lost because our plugins iterator sets a custom timer on each phase of a plugin iterator, but it gets lost on timers. I believe this is a general issue. For now we could get over that by the logger inside the reporter:

local function get_reporter(conf)
  if reporter_cache[conf] == nil then
    reporter_cache[conf] = new_zipkin_reporter(conf.http_endpoint,
                                               conf.default_service_name,
                                               conf.local_service_name,
                                               conf.connect_timeout,
                                               conf.send_timeout,
                                               conf.read_timeout,
                                               kong.log)
  end
  return reporter_cache[conf]
end

And using a method like reporter.logger.log instead of kong.log

[mayocream]

Solved by #9874

[dcarley]

Thanks!