While doing something unrelated, I noticed this code [0] that shouldn't need to exist if global_request_id is working. I threw out some debug patches [1] to dump headers. Results: [2] (nova), [3] (placement). We're tracking global_request_id ``req-a51f...``.
Nova is sending the global_request_id properly in the X-Openstack-Request-Id header, and Placement is receiving it correctly, because it's showing up in the expected spot in the Placement log line (after the opening bracket, per the logging_context_format_string in placement.conf [4]).
Placement is sending back the request_id (``req-b3ce...``) in the x-openstack-request-id header in the response. (I thought this was a bug, but it turns out this is correct per the design [5].)
So the problem is that the Nova log is printing ``None`` for the global_request_id. Based on logging_context_format_string in nova-cpu.conf [6], I expect it in the first field after the opening bracket, just like for Placement.
If the global_request_id were showing up in the Nova log, we wouldn't need to correlate the Nova and Placement sides of this conversation via the Placement request_id, and we could get rid of [0] and its usages.
I don't understand how LOG.xxx() is supposed to glean this value. Can someone help me find the disconnect?
Thanks, efried
[0] https://opendev.org/openstack/nova/src/commit/d358df32f7a2a1125962e27f242535... [1] https://review.opendev.org/#/q/topic:where-are-you-global_request_id [2] http://logs.openstack.org/86/672986/1/check/nova-live-migration/e426c8a/logs... [3] http://logs.openstack.org/86/672986/1/check/nova-live-migration/e426c8a/logs... [4] http://logs.openstack.org/86/672986/1/check/nova-live-migration/e426c8a/logs... [5] https://specs.openstack.org/openstack/oslo-specs/specs/pike/global-req-id.ht... [6] http://logs.openstack.org/86/672986/1/check/nova-live-migration/e426c8a/logs...