Hi everyone

Found that Heat doesn't keep the value of X-OpenStack-Request-ID header during request processing. Simple stack delete leads to 4 different request id, only the last of them corresponds to heat engine processing the request. Investigation shows that req-id "duplicates" twice - when client goes via redirect response returned by API and at version negotiation at every connect to API endpoint. I assume that this situation is not expected, and it really spoils work with heat api logs. Any ideas on how to make the situation more clear?

Also looks like that header name is case-dependent in some places, and Oslo-middleware and Heat handles them differently. However, it needs additional investigation.

I propose to turn off logging for successful negotiation and re-use req-id in keystoneuth during redirect. If it is ok, I plan to submit corresponding patches to upstream.

Here is a piece of log related to stack delete. Only "req-843ac3a4..." exists in the heat-engine log.

лис 07 12:21:59 ubuntu devstack@h-api.service[172816]: DEBUG heat.api.middleware.version_negotiation [None req-5b613e29-8dd9-458d-b908-4802f90c0b2f admin admin] Processing request: DELETE /heat-api/v1/8a76e6c8cc714288823dfe3677174893/stacks/stack_1 Accept: application/json {{(pid=172816) process_request /opt/stack/heat/heat/api/middleware/version_negotiation.py:57}}
лис 07 12:21:59 ubuntu devstack@h-api.service[172816]: DEBUG heat.api.middleware.version_negotiation [None req-5b613e29-8dd9-458d-b908-4802f90c0b2f admin admin] Matched versioned URI. Version: 1.0 {{(pid=172816) process_request /opt/stack/heat/heat/api/middleware/version_negotiation.py:69}}
лис 07 12:21:59 ubuntu devstack@h-api.service[172816]: INFO heat.common.wsgi [None req-ec73b5d8-5025-40e0-90d7-4010d39cb450 admin admin] Processing request: DELETE /heat-api/v1/8a76e6c8cc714288823dfe3677174893/stacks/stack_1
лис 07 12:21:59 ubuntu devstack@h-api.service[172816]: DEBUG heat.common.wsgi [None req-ec73b5d8-5025-40e0-90d7-4010d39cb450 admin admin] Calling StackController.lookup {{(pid=172816) __call__ /opt/stack/heat/heat/common/wsgi.py:823}}
лис 07 12:21:59 ubuntu devstack@h-api.service[172816]: [pid: 172816|app: 0|req: 12/24] 192.168.123.5 () {66 vars in 1391 bytes} [Mon Nov  7 12:21:59 2022] DELETE /heat-api/v1/8a76e6c8cc714288823dfe3677174893/stacks/stack_1 => generated 377 bytes in 167 msecs (HTTP/1.1 302) 5 headers in 289 bytes (1 switches on core 3)
лис 07 12:21:59 ubuntu devstack@h-api.service[172815]: DEBUG heat.api.middleware.version_negotiation [None req-f1eb3c1b-b76c-42fa-8998-31bb2cc43030 admin admin] Processing request: DELETE /heat-api/v1/8a76e6c8cc714288823dfe3677174893/stacks/stack_1/05e56d91-6b11-4e20-83f3-e2923667019b Accept: application/json {{(pid=172815) process_request /opt/stack/heat/heat/api/middleware/version_negotiation.py:57}}
лис 07 12:21:59 ubuntu devstack@h-api.service[172815]: DEBUG heat.api.middleware.version_negotiation [None req-f1eb3c1b-b76c-42fa-8998-31bb2cc43030 admin admin] Matched versioned URI. Version: 1.0 {{(pid=172815) process_request /opt/stack/heat/heat/api/middleware/version_negotiation.py:69}}
лис 07 12:21:59 ubuntu devstack@h-api.service[172815]: INFO heat.common.wsgi [None req-843ac3a4-408d-4473-844f-f4b109ad1725 admin admin] Processing request: DELETE /heat-api/v1/8a76e6c8cc714288823dfe3677174893/stacks/stack_1/05e56d91-6b11-4e20-83f3-e2923667019b
лис 07 12:21:59 ubuntu devstack@h-api.service[172815]: DEBUG heat.common.wsgi [None req-843ac3a4-408d-4473-844f-f4b109ad1725 admin admin] Calling StackController.delete {{(pid=172815) __call__ /opt/stack/heat/heat/common/wsgi.py:823}}
лис 07 12:21:59 ubuntu devstack@h-api.service[172815]: [pid: 172815|app: 0|req: 13/25] 192.168.123.5 () {66 vars in 1502 bytes} [Mon Nov  7 12:21:59 2022] DELETE /heat-api/v1/8a76e6c8cc714288823dfe3677174893/stacks/stack_1/05e56d91-6b11-4e20-83f3-e2923667019b => generated 0 bytes in 118 msecs (HTTP/1.1 204) 2 headers in 112 bytes (1 switches on core 0)