TECH-12593:make global_context global, but just for that logger instance

[ColinDKelley]

While investigating missing log contexts, we found a few problems:

1. The global_context was stored into a Thread/Fiber-local... so it would not be applied when running on a different Thread or Fiber.
2. Both the global_context and current_context were stored in a Thread/Fiber-local... meaning that they would be shared across different instance of the Logger, if you had them.
3. It was confusing the have the context managed by the Context::Handler rather than simply the Context.

The changes in this branch are:

• The global_context is stored in the logger itself, so it is global to that logger, only.
• LoggerWithContext delegates the global_context to the current_context of the base logger it was created with.
• The current_context comes from a Thread/Fiber local where the key to the name includes the logger's object_id. So it can be different for multiple logger instances.
• The current_context defaults to nil, and may also be set to nil. Whenever it has a nil value, the current_context defaults to the global_context for that logger.
• Context is now cleanly separated from ContextHandler.

Note: best reviewed with Hide whitespace.

[ColinDKelley]

This is pretty sneaky. It's the only way I could think to get Thread/Fiber-locals to also be unique for each enclosing Logger. Notice that they won't get cleaned up when the Logger goes out of scope. I don't think it's likely that anyone would create a huge number of Loggers, so we should be fine.

[ColinDKelley]

@jebentier This is still a bug. I realized it's one of the reasons I had headed down the path of tracking the global_context instance for equals?--that would be necessary in order to fix this bug. But it would be really complicated. And this bug isn't new. The code in this branch works much better in that it handles with_context on both the original logger as well as the LoggerWithContext; it just doesn't handle if you repeat the former after having logged something. That seems very unlikely.

[jebentier]

I agree that this seems unlikely and that the code required to fix this limitation is more complex than we want for this logger. Thank you for documenting it so we’re aware moving forward.

[ColinDKelley]

@jebentier Can you review the new changes here since you last reviewed?

[jebentier]

The new changes look good. Thanks for working through this. Have we been able to confirm that this resolves the bugs we were seeing when using this with Sidekiq?

[jebentier]

I agree that this seems unlikely and that the code required to fix this limitation is more complex than we want for this logger. Thank you for documenting it so we’re aware moving forward.

[hound]

Layout/LineLength: Line is too long. [176/150]

[ColinDKelley]

Have we been able to confirm that this resolves the bugs we were seeing when using this with Sidekiq?

Yes, the previous version did. But I'll be checking again with this latest version.

[ColinDKelley]

@jebentier FYI, I ran the final QA on a kube-platform and confirmed that the Sidekiq logging always contains the full context, once we get fully bootstrapped. As before there's a small window at the start when a ServiceDiscovery thread starts logging before the LoggerMixin logger is in place. That's not new, and I think we can live with it.

Here are the first 3 examples from a task pod. Note that the inline context is winding up in the progname parameter:

{"app":{"@timestamp":"2023-09-13T11:06:02.898978-07:00","severity":"INFO","host":"task-slow-7fb96d64f5-dzgd7","tid":"1qo4","service_name":"rr_slow_task_queue","progname":"{:invoca_service_discovery=>{:metric=>\"discover.attempt\", :datacenter=>\"aws-us-east-1\", :service=>\"vault\", :tags=>[\"active\"], :count=>1, :timers=>[], :current_datacenter=>\"aws-us-east-1\"}}","message":"{:invoca_service_discovery=>{:metric=>\"discover.attempt\", :datacenter=>\"aws-us-east-1\", :service=>\"vault\", :tags=>[\"active\"], :count=>1, :timers=>[], :current_datacenter=>\"aws-us-east-1\"}}: Invoca::ServiceDiscovery.discover metric report"}}
{"app":{"@timestamp":"2023-09-13T11:06:02.899689-07:00","severity":"INFO","host":"task-slow-7fb96d64f5-dzgd7","tid":"1qo4","service_name":"rr_slow_task_queue","progname":"{:invoca_service_discovery=>{:metric=>\"discover.unexpected_cross_datacenter\", :datacenter=>\"aws-us-east-1\", :service=>\"vault\", :tags=>[], :count=>0, :timers=>[], :current_datacenter=>\"aws-us-east-1\"}}","message":"{:invoca_service_discovery=>{:metric=>\"discover.unexpected_cross_datacenter\", :datacenter=>\"aws-us-east-1\", :service=>\"vault\", :tags=>[], :count=>0, :timers=>[], :current_datacenter=>\"aws-us-east-1\"}}: Invoca::ServiceDiscovery.discover metric report"}}
{"app":{"@timestamp":"2023-09-13T11:06:02.900647-07:00","severity":"INFO","host":"task-slow-7fb96d64f5-dzgd7","tid":"1qo4","service_name":"rr_slow_task_queue","progname":"{:invoca_service_discovery=>{:metric=>\"discover.timing\", :datacenter=>\"aws-us-east-1\", :service=>\"vault\", :tags=>[\"active\"], :count=>0, :timers=>[60.919656000010036], :current_datacenter=>\"aws-us-east-1\"}}","message":"{:invoca_service_discovery=>{:metric=>\"discover.timing\", :datacenter=>\"aws-us-east-1\", :service=>\"vault\", :tags=>[\"active\"], :count=>0, :timers=>[60.919656000010036], :current_datacenter=>\"aws-us-east-1\"}}: Invoca::ServiceDiscovery.discover metric report"}}