request_id from tiqr log and x-stepup-request-id HTTP header do not match

[pmeulen]

Steps to reproduce:

Make a some request to tiqr. E.g. curl -vvv https://tiqr.dev.openconext.local/request-id-log-test

The headers from the response will return a x-stepup-request-id header:

< cache-control: max-age=0, no-cache, no-store, private
< content-type: text/html; charset=UTF-8
< date: Mon, 02 Sep 2024 11:57:23 GMT
< server: Apache
< x-content-type-options: nosniff
< x-stepup-request-id: f73db475d8cbfac08c4ee5602699c9a2
< strict-transport-security: max-age=34214400

Apache is configured to log this header so that the apache logs and the tiqr logs can be matched.

However tiqr logs a different request_id (2ade7528425887588a8689eb6aff1863) in its log:

{"message":"Uncaught PHP Exception Symfony\\Component\\HttpKernel\\Exception\\NotFoundHttpException: \"No route found for \"GET https://tiqr.surfconext.nl/request-id-log-test\"\" at RouterListener.php line 127","context":{"exception":{"class":"Symfony\\Component\\HttpKernel\\Exception\\NotFoundHttpException","message":"No route found for \"GET https://tiqr.surfconext.nl/request-id-log-test\"","code":0,"file":"/var/www/html/vendor/symfony/http-kernel/EventListener/RouterListener.php:127","previous":{"class":"Symfony\\Component\\Routing\\Exception\\ResourceNotFoundException","message":"No routes found for \"/request-id-log-test/\".","code":0,"file":"/var/www/html/vendor/symfony/routing/Matcher/Dumper/CompiledUrlMatcherTrait.php:70"}}},"level":400,"level_name":"ERROR","channel":"request","datetime":"2024-09-02T13:57:23+02:00","extra":{"art":"18839","server":"tiqr.dev.openconext.local","application":"stepup-tiqr","request_id":"2ade7528425887588a8689eb6aff1863"}}

request_id and x-stepup-request-id must match.

[MKodde]

After the recent logging (and session) improvements. I no longer observe this discrepancy (at least, not in my dev-container).

Some observations:

1. The GSSP 'sari' is not the same for every http request during an authentication request. So that ID will change on every HTTP request
2. The x-stepup-request-id now matches the ID printed on the error report (and in the logs)
3. With 3. Improve handling of qr timeout & state errors when polling #210 and Add the session id derived id to polling requests #211 we now also have a means to correlate between access and app logs.
4. I still observer some strange cookie behavior in Tiqr, this I will investigate with @quartje later today.