From 86d825594b3ffcca352afeb1d2cad4846ef9f9da Mon Sep 17 00:00:00 2001 From: Kay Joosten Date: Tue, 21 Apr 2026 17:46:21 +0200 Subject: [PATCH 1/8] feat: add correlation ID infrastructure for SAML flow log tracing MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Introduces components to address issue #1971: - CorrelationId: immutable value object wrapping a hex correlation ID - CurrentCorrelationId: mutable DI singleton holding the active correlation ID for the current HTTP request; read by the Monolog processor - CorrelationIdRepository: session-backed store with store/find/link methods; no-ops safely when no session is available (CLI, unit tests) - CorrelationIdService: orchestrator with mint/link/resolve used by Corto: mint(requestId) — generate a new ID if none exists (back-button safe) link(target, src) — copy an ID to a second SAML request ID resolve(requestId) — look up and push into CurrentCorrelationId - CorrelationIdProcessor: Monolog processor stamping correlation_id on every log record via CurrentCorrelationId - TestLogHandler: in-memory Monolog handler for Behat log assertions, registered in ci and test monolog config DI wiring: services.yml registers all services; logging.yml registers the processor. DiContainer exposes getCorrelationIdService() as the bridge from legacy Corto code into Symfony. --- config/packages/ci/monolog.yaml | 5 + config/packages/test/monolog.yaml | 3 + config/services/logging.yml | 6 ++ config/services/services.yml | 25 ++++- .../EngineBlock/Application/DiContainer.php | 16 +++ .../Processor/CorrelationIdProcessor.php | 37 +++++++ .../EngineBlock/Request/CorrelationId.php | 34 +++++++ .../Request/CorrelationIdRepository.php | 99 +++++++++++++++++++ .../Request/CorrelationIdService.php | 76 ++++++++++++++ .../Request/CurrentCorrelationId.php | 39 ++++++++ 10 files changed, 338 insertions(+), 2 deletions(-) create mode 100644 config/packages/ci/monolog.yaml create mode 100644 src/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessor.php create mode 100644 src/OpenConext/EngineBlock/Request/CorrelationId.php create mode 100644 src/OpenConext/EngineBlock/Request/CorrelationIdRepository.php create mode 100644 src/OpenConext/EngineBlock/Request/CorrelationIdService.php create mode 100644 src/OpenConext/EngineBlock/Request/CurrentCorrelationId.php diff --git a/config/packages/ci/monolog.yaml b/config/packages/ci/monolog.yaml new file mode 100644 index 0000000000..6753119973 --- /dev/null +++ b/config/packages/ci/monolog.yaml @@ -0,0 +1,5 @@ +monolog: + handlers: + test_log_handler: + type: service + id: OpenConext\EngineBlockFunctionalTestingBundle\Log\TestLogHandler diff --git a/config/packages/test/monolog.yaml b/config/packages/test/monolog.yaml index 0866a82e37..06b9dd396f 100644 --- a/config/packages/test/monolog.yaml +++ b/config/packages/test/monolog.yaml @@ -12,3 +12,6 @@ monolog: type: stream path: "%kernel.logs_dir%/%kernel.environment%.log" level: DEBUG + test_log_handler: + type: service + id: OpenConext\EngineBlockFunctionalTestingBundle\Log\TestLogHandler diff --git a/config/services/logging.yml b/config/services/logging.yml index 9229a34f98..18b1f60a8a 100644 --- a/config/services/logging.yml +++ b/config/services/logging.yml @@ -30,6 +30,12 @@ services: tags: - { name: monolog.processor } + OpenConext\EngineBlock\Logger\Processor\CorrelationIdProcessor: + arguments: + - '@OpenConext\EngineBlock\Request\CurrentCorrelationId' + tags: + - { name: monolog.processor } + OpenConext\EngineBlock\Logger\Processor\SessionIdProcessor: tags: - { name: monolog.processor } diff --git a/config/services/services.yml b/config/services/services.yml index e623a8b286..b45b6ae307 100644 --- a/config/services/services.yml +++ b/config/services/services.yml @@ -18,7 +18,6 @@ services: class: OpenConext\EngineBlockBundle\HealthCheck\DoctrineConnectionHealthCheck arguments: - '%monitor_database_health_check_query%' - - '@logger' calls: - [ setEntityManager, ['@?doctrine.orm.entity_manager']] tags: @@ -57,6 +56,20 @@ services: - '@OpenConext\EngineBlock\Request\UniqidGenerator' public: true + OpenConext\EngineBlock\Request\CurrentCorrelationId: + public: true + + OpenConext\EngineBlock\Request\CorrelationIdRepository: + public: true + arguments: + - '@request_stack' + + OpenConext\EngineBlock\Request\CorrelationIdService: + public: true + arguments: + - '@OpenConext\EngineBlock\Request\CorrelationIdRepository' + - '@OpenConext\EngineBlock\Request\CurrentCorrelationId' + OpenConext\EngineBlockBundle\Security\Http\EntryPoint\JsonBasicAuthenticationEntryPoint: arguments: - 'engine-api.%domain%' @@ -158,7 +171,6 @@ services: - '@OpenConext\EngineBlock\Xml\DocumentSigner' - '@OpenConext\EngineBlock\Service\TimeProvider\TimeProvider' - '%metadata_add_requested_attributes%' - - "%metadata_expiration_time%" OpenConext\EngineBlock\Xml\MetadataProvider: arguments: @@ -379,3 +391,12 @@ services: class: OpenConext\EngineBlockBundle\Sbs\SbsAttributeMerger arguments: - "%sram.allowed_attributes%" + + EngineBlock_Saml2_AuthnRequestSessionRepository: + class: EngineBlock_Saml2_AuthnRequestSessionRepository + public: true + arguments: + - '@request_stack' + + OpenConext\EngineBlockFunctionalTestingBundle\Log\TestLogHandler: + public: true diff --git a/library/EngineBlock/Application/DiContainer.php b/library/EngineBlock/Application/DiContainer.php index 03d4a6f3e6..79ff6486fe 100644 --- a/library/EngineBlock/Application/DiContainer.php +++ b/library/EngineBlock/Application/DiContainer.php @@ -613,4 +613,20 @@ public function getNameIdSubstituteResolver() { return new EngineBlock_Arp_NameIdSubstituteResolver($this->container->get('engineblock.compat.logger')); } + + /** + * @return \OpenConext\EngineBlock\Request\CorrelationIdService + */ + public function getCorrelationIdService(): \OpenConext\EngineBlock\Request\CorrelationIdService + { + return $this->container->get(\OpenConext\EngineBlock\Request\CorrelationIdService::class); + } + + /** + * @return EngineBlock_Saml2_AuthnRequestSessionRepository + */ + public function getAuthnRequestSessionRepository(): EngineBlock_Saml2_AuthnRequestSessionRepository + { + return $this->container->get(EngineBlock_Saml2_AuthnRequestSessionRepository::class); + } } diff --git a/src/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessor.php b/src/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessor.php new file mode 100644 index 0000000000..8b190f04c0 --- /dev/null +++ b/src/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessor.php @@ -0,0 +1,37 @@ +extra['correlation_id'] = $this->correlationId->get(); + + return $record; + } +} diff --git a/src/OpenConext/EngineBlock/Request/CorrelationId.php b/src/OpenConext/EngineBlock/Request/CorrelationId.php new file mode 100644 index 0000000000..dd5c516499 --- /dev/null +++ b/src/OpenConext/EngineBlock/Request/CorrelationId.php @@ -0,0 +1,34 @@ +requestStack->getSession(); + } catch (SessionNotFoundException) { + return; + } + + $ids = $session->get(self::SESSION_KEY, []); + $ids[$requestId] = $correlationId->correlationId; + $session->set(self::SESSION_KEY, $ids); + } + + /** + * Copies the correlation ID from $sourceRequestId to $targetRequestId. + * No-op when source is not found or no session is available. + */ + public function link(string $targetRequestId, string $sourceRequestId): void + { + try { + $session = $this->requestStack->getSession(); + } catch (SessionNotFoundException) { + return; + } + + $ids = $session->get(self::SESSION_KEY, []); + + if (!array_key_exists($sourceRequestId, $ids)) { + return; + } + + $ids[$targetRequestId] = $ids[$sourceRequestId]; + $session->set(self::SESSION_KEY, $ids); + } + + /** + * Returns the CorrelationId for $requestId, or null when not found. + * Returns null when no session is available. + */ + public function find(string $requestId): ?CorrelationId + { + try { + $session = $this->requestStack->getSession(); + } catch (SessionNotFoundException) { + return null; + } + + $value = $session->get(self::SESSION_KEY, [])[$requestId] ?? null; + + return $value !== null ? new CorrelationId($value) : null; + } +} diff --git a/src/OpenConext/EngineBlock/Request/CorrelationIdService.php b/src/OpenConext/EngineBlock/Request/CorrelationIdService.php new file mode 100644 index 0000000000..66d10bb481 --- /dev/null +++ b/src/OpenConext/EngineBlock/Request/CorrelationIdService.php @@ -0,0 +1,76 @@ +repository->find($requestId) === null) { + $this->repository->store($requestId, CorrelationId::mint()); + } + } + + /** + * Copies the correlation ID from $sourceRequestId to $targetRequestId. + */ + public function link(string $targetRequestId, string $sourceRequestId): void + { + $this->repository->link($targetRequestId, $sourceRequestId); + } + + /** + * Looks up the correlation ID for $requestId and sets it as the active ID + * in CurrentCorrelationId so all subsequent log entries carry it. + * No-op when $requestId is null or not found. + */ + public function resolve(?string $requestId): void + { + if ($requestId === null) { + return; + } + + $cid = $this->repository->find($requestId); + + if ($cid !== null) { + $this->current->set($cid->correlationId); + } + } +} diff --git a/src/OpenConext/EngineBlock/Request/CurrentCorrelationId.php b/src/OpenConext/EngineBlock/Request/CurrentCorrelationId.php new file mode 100644 index 0000000000..f50add505b --- /dev/null +++ b/src/OpenConext/EngineBlock/Request/CurrentCorrelationId.php @@ -0,0 +1,39 @@ +correlationId = $correlationId; + } + + public function get(): ?string + { + return $this->correlationId; + } +} From b11228b332a2915d442a08b6244a5a8f79634365 Mon Sep 17 00:00:00 2001 From: Kay Joosten Date: Tue, 21 Apr 2026 17:46:33 +0200 Subject: [PATCH 2/8] feat: wire correlation ID through all four SAML flow legs MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Migrates AuthnRequestSessionRepository from \$_SESSION to the Symfony session (via RequestStack) and registers it as a DI service, so all call sites use DiContainer instead of constructing it with a logger. Each HTTP leg resolves the correlation ID at the top of its handler: Leg 1 SSO — mint() + resolve() in SingleSignOn (WAYF path); mint() + link() + resolve() in ProxyServer (direct path) Leg 2 ContinueToIdp — resolve() so log lines in this leg carry the ID; ProxyServer also calls link() to tie the IdP request ID to the SP request ID (idempotent second resolve) Leg 3 ACS — resolve() via InResponseTo (IdP request ID) Leg 4 Consent — resolve() via SP request ID in ProvideConsent and ProcessConsent --- .../Module/Service/AssertionConsumer.php | 3 + .../Corto/Module/Service/ContinueToIdp.php | 13 ++- .../Corto/Module/Service/ProcessConsent.php | 6 ++ .../Corto/Module/Service/ProvideConsent.php | 7 +- .../Corto/Module/Service/SingleSignOn.php | 6 +- library/EngineBlock/Corto/ProxyServer.php | 25 ++++- .../Saml2/AuthnRequestSessionRepository.php | 92 ++++++++++--------- 7 files changed, 105 insertions(+), 47 deletions(-) diff --git a/library/EngineBlock/Corto/Module/Service/AssertionConsumer.php b/library/EngineBlock/Corto/Module/Service/AssertionConsumer.php index 751d1ddd4f..cf13c5a962 100644 --- a/library/EngineBlock/Corto/Module/Service/AssertionConsumer.php +++ b/library/EngineBlock/Corto/Module/Service/AssertionConsumer.php @@ -89,6 +89,9 @@ public function serve($serviceName, Request $httpRequest) $receivedRequest = $this->_server->getReceivedRequestFromResponse($receivedResponse); $application = EngineBlock_ApplicationSingleton::getInstance(); + + $correlationIdService = $application->getDiContainer()->getCorrelationIdService(); + $correlationIdService->resolve($receivedResponse->getInResponseTo()); $log = $application->getLogInstance(); if(!$receivedRequest instanceof EngineBlock_Saml2_AuthnRequestAnnotationDecorator){ diff --git a/library/EngineBlock/Corto/Module/Service/ContinueToIdp.php b/library/EngineBlock/Corto/Module/Service/ContinueToIdp.php index ee3a3a0f3b..1865759fe9 100644 --- a/library/EngineBlock/Corto/Module/Service/ContinueToIdp.php +++ b/library/EngineBlock/Corto/Module/Service/ContinueToIdp.php @@ -85,7 +85,9 @@ public function serve($serviceName, Request $httpRequest) ); } - $authnRequestRepository = new EngineBlock_Saml2_AuthnRequestSessionRepository($this->_server->getLogger()); + $authnRequestRepository = EngineBlock_ApplicationSingleton::getInstance() + ->getDiContainer() + ->getAuthnRequestSessionRepository(); $request = $authnRequestRepository->findRequestById($id); if (!$request) { @@ -94,6 +96,15 @@ public function serve($serviceName, Request $httpRequest) ); } + // Resolve here so log entries emitted during this leg carry the correlation ID. + // ProxyServer::sendAuthenticationRequest will also call mint()+link()+resolve() + // on the SP request ID — that is idempotent and sets the same value. + // The IdP request ID is only resolvable in AssertionConsumer (Leg 3). + $correlationIdService = EngineBlock_ApplicationSingleton::getInstance() + ->getDiContainer() + ->getCorrelationIdService(); + $correlationIdService->resolve($id); + // Flush log if SP or IdP has additional logging enabled if ($request->isDebugRequest()) { $sp = $this->getEngineSpRole($this->_server); diff --git a/library/EngineBlock/Corto/Module/Service/ProcessConsent.php b/library/EngineBlock/Corto/Module/Service/ProcessConsent.php index dd882adcc2..e39c46216f 100644 --- a/library/EngineBlock/Corto/Module/Service/ProcessConsent.php +++ b/library/EngineBlock/Corto/Module/Service/ProcessConsent.php @@ -85,6 +85,12 @@ public function serve($serviceName, Request $httpRequest) $response = $processStep->getResponse(); $request = $this->_server->getReceivedRequestFromResponse($response); + + $correlationIdService = EngineBlock_ApplicationSingleton::getInstance() + ->getDiContainer() + ->getCorrelationIdService(); + $correlationIdService->resolve($request->getId()); + $serviceProvider = $this->_server->getRepository()->fetchServiceProviderByEntityId($request->getIssuer()->getValue()); $destinationMetadata = EngineBlock_SamlHelper::getDestinationSpMetadata( diff --git a/library/EngineBlock/Corto/Module/Service/ProvideConsent.php b/library/EngineBlock/Corto/Module/Service/ProvideConsent.php index cf8cc3d3ab..76905ff072 100644 --- a/library/EngineBlock/Corto/Module/Service/ProvideConsent.php +++ b/library/EngineBlock/Corto/Module/Service/ProvideConsent.php @@ -100,6 +100,11 @@ public function serve($serviceName, Request $httpRequest) $receivedRequest = $this->_server->getReceivedRequestFromResponse($response); + $correlationIdService = EngineBlock_ApplicationSingleton::getInstance() + ->getDiContainer() + ->getCorrelationIdService(); + $correlationIdService->resolve($receivedRequest->getId()); + // update previous response with current response $this->_processingStateHelper->updateStepResponseByRequestId( $receivedRequest->getId(), @@ -107,7 +112,7 @@ public function serve($serviceName, Request $httpRequest) $response ); - $request = $this->_server->getReceivedRequestFromResponse($response); + $request = $receivedRequest; $serviceProvider = $this->_server->getRepository()->fetchServiceProviderByEntityId($request->getIssuer()->getValue()); $spMetadataChain = EngineBlock_SamlHelper::getSpRequesterChain( $serviceProvider, diff --git a/library/EngineBlock/Corto/Module/Service/SingleSignOn.php b/library/EngineBlock/Corto/Module/Service/SingleSignOn.php index 54e2e6233a..8d769e847c 100644 --- a/library/EngineBlock/Corto/Module/Service/SingleSignOn.php +++ b/library/EngineBlock/Corto/Module/Service/SingleSignOn.php @@ -240,9 +240,13 @@ public function serve($serviceName, Request $httpRequest) return; } - $authnRequestRepository = new EngineBlock_Saml2_AuthnRequestSessionRepository($log); + $authnRequestRepository = $application->getDiContainer()->getAuthnRequestSessionRepository(); $authnRequestRepository->store($request); + $correlationIdService = $application->getDiContainer()->getCorrelationIdService(); + $correlationIdService->mint($request->getId()); + $correlationIdService->resolve($request->getId()); + // Show WAYF $log->info("Multiple candidate IdPs: redirecting to WAYF"); $this->_showWayf($request, $candidateIDPs); diff --git a/library/EngineBlock/Corto/ProxyServer.php b/library/EngineBlock/Corto/ProxyServer.php index ed645a1911..529dbb10dc 100644 --- a/library/EngineBlock/Corto/ProxyServer.php +++ b/library/EngineBlock/Corto/ProxyServer.php @@ -467,10 +467,18 @@ public function sendAuthenticationRequest( $authenticationState->startAuthenticationOnBehalfOf($ebRequest->getId(), $serviceProvider); // Store the original Request - $authnRequestRepository = new EngineBlock_Saml2_AuthnRequestSessionRepository($this->_logger); + $authnRequestRepository = EngineBlock_ApplicationSingleton::getInstance() + ->getDiContainer() + ->getAuthnRequestSessionRepository(); $authnRequestRepository->store($spRequest); $authnRequestRepository->link($ebRequest, $spRequest); + $correlationIdService = EngineBlock_ApplicationSingleton::getInstance() + ->getDiContainer() + ->getCorrelationIdService(); + $correlationIdService->mint($spRequest->getId()); + $correlationIdService->link($ebRequest->getId(), $spRequest->getId()); + $correlationIdService->resolve($spRequest->getId()); $this->getBindingsModule()->send($ebRequest, $identityProvider); } @@ -552,10 +560,19 @@ public function sendStepupAuthenticationRequest( // Link with the original Request - $authnRequestRepository = new EngineBlock_Saml2_AuthnRequestSessionRepository($this->_logger); + $authnRequestRepository = EngineBlock_ApplicationSingleton::getInstance() + ->getDiContainer() + ->getAuthnRequestSessionRepository(); $authnRequestRepository->store($spRequest); $authnRequestRepository->link($ebRequest, $spRequest); + $correlationIdService = EngineBlock_ApplicationSingleton::getInstance() + ->getDiContainer() + ->getCorrelationIdService(); + $correlationIdService->mint($spRequest->getId()); + $correlationIdService->link($ebRequest->getId(), $spRequest->getId()); + $correlationIdService->resolve($spRequest->getId()); + $this->getBindingsModule()->send($ebRequest, $identityProvider, true); } @@ -1097,7 +1114,9 @@ public function getReceivedRequestFromResponse(EngineBlock_Saml2_ResponseAnnotat public function findRequestFromRequestId(string $requestId): ?EngineBlock_Saml2_AuthnRequestAnnotationDecorator { - $authnRequestRepository = new EngineBlock_Saml2_AuthnRequestSessionRepository($this->getLogger()); + $authnRequestRepository = EngineBlock_ApplicationSingleton::getInstance() + ->getDiContainer() + ->getAuthnRequestSessionRepository(); $spRequestId = $authnRequestRepository->findLinkedRequestId($requestId); if ($spRequestId === null) { diff --git a/library/EngineBlock/Saml2/AuthnRequestSessionRepository.php b/library/EngineBlock/Saml2/AuthnRequestSessionRepository.php index be612b395c..98728df6d6 100644 --- a/library/EngineBlock/Saml2/AuthnRequestSessionRepository.php +++ b/library/EngineBlock/Saml2/AuthnRequestSessionRepository.php @@ -16,81 +16,83 @@ * limitations under the License. */ +use Symfony\Component\HttpFoundation\Exception\SessionNotFoundException; +use Symfony\Component\HttpFoundation\RequestStack; + /** * Session storage for Authentication Requests. Store AuthnRequests and link requests together. + * + * Uses the Symfony session bag under two keys: + * 'SAMLRequest' — map of requestId => AuthnRequestAnnotationDecorator + * 'SAMLRequestLinks' — map of idpRequestId => spRequestId + * + * All methods are safe no-ops when no session is available (unit tests, CLI). */ class EngineBlock_Saml2_AuthnRequestSessionRepository { - /** - * @var Psr\Log\LoggerInterface - */ - private $sessionLog; + private const SESSION_KEY_REQUESTS = 'SAMLRequest'; + private const SESSION_KEY_LINKS = 'SAMLRequestLinks'; /** - * @var + * @var RequestStack */ - private $requestStorage; + private $requestStack; - /** - * @var array - */ - private $linkStorage; - - /** - * @param Psr\Log\LoggerInterface $sessionLog - */ - public function __construct(Psr\Log\LoggerInterface $sessionLog) + public function __construct(RequestStack $requestStack) { - if (!isset($_SESSION['SAMLRequest'])) { - $_SESSION['SAMLRequest'] = array(); - } - $this->requestStorage = &$_SESSION['SAMLRequest']; - - if (!isset($_SESSION['SAMLRequestLinks'])) { - $_SESSION['SAMLRequestLinks'] = array(); - } - $this->linkStorage = &$_SESSION['SAMLRequestLinks']; - - $this->sessionLog = $sessionLog; + $this->requestStack = $requestStack; } /** * @param string $requestId - * @return EngineBlock_Saml2_AuthnRequestAnnotationDecorator + * @return EngineBlock_Saml2_AuthnRequestAnnotationDecorator|null */ public function findRequestById($requestId) { - if (!isset($this->requestStorage[$requestId])) { + try { + $session = $this->requestStack->getSession(); + } catch (SessionNotFoundException $e) { return null; } - return $this->requestStorage[$requestId]; + return $session->get(self::SESSION_KEY_REQUESTS, [])[$requestId] ?? null; } /** - * @param $requestId + * @param string|null $requestId * @return string|null */ public function findLinkedRequestId($requestId) { - // Check the session for a AuthnRequest with the given ID - // Expect to get back an AuthnRequest issued by EngineBlock and destined for the IdP - if (!$requestId || !isset($this->linkStorage[$requestId])) { + if (!$requestId) { + return null; + } + + try { + $session = $this->requestStack->getSession(); + } catch (SessionNotFoundException $e) { return null; } - return $this->linkStorage[$requestId]; + return $session->get(self::SESSION_KEY_LINKS, [])[$requestId] ?? null; } /** * @param EngineBlock_Saml2_AuthnRequestAnnotationDecorator $spRequest * @return $this */ - public function store( - EngineBlock_Saml2_AuthnRequestAnnotationDecorator $spRequest - ) { - // Store the original Request - $this->requestStorage[$spRequest->getId()] = $spRequest; + public function store(EngineBlock_Saml2_AuthnRequestAnnotationDecorator $spRequest) + { + try { + $session = $this->requestStack->getSession(); + } catch (SessionNotFoundException $e) { + return $this; + } + + $requests = $session->get(self::SESSION_KEY_REQUESTS, []); + $requests[$spRequest->getId()] = $spRequest; + $session->set(self::SESSION_KEY_REQUESTS, $requests); + return $this; } @@ -103,8 +105,16 @@ public function link( EngineBlock_Saml2_AuthnRequestAnnotationDecorator $fromRequest, EngineBlock_Saml2_AuthnRequestAnnotationDecorator $toRequest ) { - // Store the mapping from the new request ID to the original request ID - $this->linkStorage[$fromRequest->getId()] = $toRequest->getId(); + try { + $session = $this->requestStack->getSession(); + } catch (SessionNotFoundException $e) { + return $this; + } + + $links = $session->get(self::SESSION_KEY_LINKS, []); + $links[$fromRequest->getId()] = $toRequest->getId(); + $session->set(self::SESSION_KEY_LINKS, $links); + return $this; } } From 7e17a65dfc39b52bccbc7726b2476a38e9a2e131 Mon Sep 17 00:00:00 2001 From: Kay Joosten Date: Tue, 21 Apr 2026 17:46:45 +0200 Subject: [PATCH 3/8] test: add tests and Behat feature for correlation ID logging Unit tests: - CorrelationIdRepositoryTest: store/find/link + SessionNotFoundException safety - CorrelationIdServiceTest: mint idempotency, link, resolve, null safety - CorrelationIdFlowTest: end-to-end simulation of all four SAML legs (WAYF, direct, concurrent flows, back-button replay guard) - CorrelationIdProcessorTest: stamps correlation_id; null when not set - AuthnRequestSessionRepositoryTest: updated to inject RequestStack + MockArraySessionStorage (logger constructor removed) - ProcessConsentTest / ProvideConsentTest: inject RequestStack-backed repository; stub getReceivedRequestFromResponse for isolation Behat: - CorrelationId.feature: WAYF and direct path scenarios assert every log record carries a non-null correlation_id field - LoggingContext: @BeforeScenario reset + "each log record should contain a :field field" step - TestLogHandler wired into behat.yml default suite contexts --- .../Features/Context/LoggingContext.php | 82 +++++++++ .../Features/CorrelationId.feature | 69 ++++++++ .../Log/TestLogHandler.php | 63 +++++++ tests/behat.yml | 2 + .../Module/Service/ProcessConsentTest.php | 19 +- .../Module/Service/ProvideConsentTest.php | 19 +- .../AuthnRequestSessionRepositoryTest.php | 145 ++++++++++++++++ .../Processor/CorrelationIdProcessorTest.php | 75 ++++++++ .../Request/CorrelationIdFlowTest.php | 162 ++++++++++++++++++ .../Request/CorrelationIdRepositoryTest.php | 128 ++++++++++++++ .../Request/CorrelationIdServiceTest.php | 103 +++++++++++ 11 files changed, 863 insertions(+), 4 deletions(-) create mode 100644 src/OpenConext/EngineBlockFunctionalTestingBundle/Features/Context/LoggingContext.php create mode 100644 src/OpenConext/EngineBlockFunctionalTestingBundle/Features/CorrelationId.feature create mode 100644 src/OpenConext/EngineBlockFunctionalTestingBundle/Log/TestLogHandler.php create mode 100644 tests/library/EngineBlock/Test/Saml2/AuthnRequestSessionRepositoryTest.php create mode 100644 tests/unit/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessorTest.php create mode 100644 tests/unit/OpenConext/EngineBlock/Request/CorrelationIdFlowTest.php create mode 100644 tests/unit/OpenConext/EngineBlock/Request/CorrelationIdRepositoryTest.php create mode 100644 tests/unit/OpenConext/EngineBlock/Request/CorrelationIdServiceTest.php diff --git a/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/Context/LoggingContext.php b/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/Context/LoggingContext.php new file mode 100644 index 0000000000..f636da2436 --- /dev/null +++ b/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/Context/LoggingContext.php @@ -0,0 +1,82 @@ +logHandler->reset(); + } + + /** + * @Then each log record should contain a :field field + */ + public function eachLogRecordShouldContainField(string $field): void + { + $records = $this->logHandler->getRecords(); + + Assert::assertNotEmpty($records, 'No log records were captured during this scenario.'); + + foreach ($records as $index => $record) { + Assert::assertArrayHasKey( + $field, + $record->extra, + sprintf( + 'Log record #%d (channel=%s, message="%s") is missing extra field "%s".', + $index, + $record->channel, + $record->message, + $field, + ), + ); + + Assert::assertNotNull( + $record->extra[$field], + sprintf( + 'Log record #%d (channel=%s, message="%s") has a null value for extra field "%s".', + $index, + $record->channel, + $record->message, + $field, + ), + ); + } + } +} diff --git a/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/CorrelationId.feature b/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/CorrelationId.feature new file mode 100644 index 0000000000..aca0a65f8c --- /dev/null +++ b/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/CorrelationId.feature @@ -0,0 +1,69 @@ +Feature: + In order to trace a complete authentication flow across log entries + As a SURF operator + I need a single correlation_id to appear in every log record belonging to the same SAML flow + + Background: + Given an EngineBlock instance on "dev.openconext.local" + And no registered SPs + And no registered Idps + And a Service Provider named "CorrId-SP" + + # ── WAYF path ────────────────────────────────────────────────────────────── + # Two IdPs are registered, so the WAYF is shown after the initial SSO request. + # The correlation ID is minted in SingleSignOn.serve(), propagated to + # ContinueToIdp (user picks an IdP), then forwarded to the IdP request via + # link(), and finally picked up in AssertionConsumer and ProvideConsent/ + # ProcessConsent. A complete round-trip through all four HTTP legs must + # succeed without error. + Scenario: A user authenticating via the WAYF completes the full four-leg flow + Given an Identity Provider named "CorrId-IdP-A" + And an Identity Provider named "CorrId-IdP-B" + When I log in at "CorrId-SP" + And I select "CorrId-IdP-A" on the WAYF + And I pass through EngineBlock + And I pass through the IdP + And I give my consent + And I pass through EngineBlock + Then the url should match "functional-testing/CorrId-SP/acs" + And each log record should contain a "correlation_id" field + + # ── Direct path (no WAYF) ─────────────────────────────────────────────────── + # When only one IdP is available the WAYF is skipped; the correlation ID is + # minted inside ProxyServer.sendAuthenticationRequest() and linked to the IdP + # request. AssertionConsumer and consent legs must resolve it from the IdP + # request ID stored in InResponseTo. + Scenario: A user authenticating without the WAYF completes the full flow + Given an Identity Provider named "CorrId-IdP-Only" + When I log in at "CorrId-SP" + And I pass through EngineBlock + And I pass through the IdP + And I give my consent + And I pass through EngineBlock + Then the url should match "functional-testing/CorrId-SP/acs" + And each log record should contain a "correlation_id" field + + # ── Concurrent flows ──────────────────────────────────────────────────────── + # Two simultaneous authentications in separate browser tabs share the same PHP + # session. Each flow must mint its own correlation ID and the two IDs must + # not bleed into each other. Both flows must complete successfully and land + # on the correct SP ACS URL. + # Requires the @functional tag to use the Chrome driver (browser tabs need JS). + @functional + Scenario: Two concurrent authentication flows each complete independently + Given an Identity Provider named "CorrId-IdP-A" + And an Identity Provider named "CorrId-IdP-B" + When I open 2 browser tabs identified by "Tab-A, Tab-B" + And I switch to "Tab-A" + And I log in at "CorrId-SP" + And I select "CorrId-IdP-A" on the WAYF + And I switch to "Tab-B" + And I log in at "CorrId-SP" + And I select "CorrId-IdP-B" on the WAYF + And I pass through the IdP + And I give my consent + Then the url should match "functional-testing/CorrId-SP/acs" + And I switch to "Tab-A" + And I pass through the IdP + And I give my consent + Then the url should match "functional-testing/CorrId-SP/acs" diff --git a/src/OpenConext/EngineBlockFunctionalTestingBundle/Log/TestLogHandler.php b/src/OpenConext/EngineBlockFunctionalTestingBundle/Log/TestLogHandler.php new file mode 100644 index 0000000000..ddf51e45d7 --- /dev/null +++ b/src/OpenConext/EngineBlockFunctionalTestingBundle/Log/TestLogHandler.php @@ -0,0 +1,63 @@ +records[] = $record; + } + + /** + * Returns all captured log records since the last reset. + * + * @return LogRecord[] + */ + public function getRecords(): array + { + return $this->records; + } + + /** + * Clears all captured log records. + */ + public function reset(): void + { + $this->records = []; + } +} diff --git a/tests/behat.yml b/tests/behat.yml index aa9ecbf600..3988906fe8 100644 --- a/tests/behat.yml +++ b/tests/behat.yml @@ -43,6 +43,8 @@ default: serviceRegistryFixture: '@engineblock.functional_testing.fixture.service_registry' - OpenConext\EngineBlockFunctionalTestingBundle\Features\Context\TranslationContext: mockTranslator: '@engineblock.functional_testing.mock.translator' + - OpenConext\EngineBlockFunctionalTestingBundle\Features\Context\LoggingContext: + logHandler: '@OpenConext\EngineBlockFunctionalTestingBundle\Log\TestLogHandler' - OpenConext\EngineBlockFunctionalTestingBundle\Features\Context\MinkContext: functional: mink_session: chrome diff --git a/tests/library/EngineBlock/Test/Corto/Module/Service/ProcessConsentTest.php b/tests/library/EngineBlock/Test/Corto/Module/Service/ProcessConsentTest.php index 3b289e97d4..521f969b1f 100644 --- a/tests/library/EngineBlock/Test/Corto/Module/Service/ProcessConsentTest.php +++ b/tests/library/EngineBlock/Test/Corto/Module/Service/ProcessConsentTest.php @@ -184,6 +184,19 @@ private function mockProxyServer() )) ->setBindingsModule($this->mockBindingsModule()); + // Stub getReceivedRequestFromResponse so tests do not depend on DI-wired + // AuthnRequestSessionRepository being populated during the test. + $spRequest = new AuthnRequest(); + $spRequest->setId('SPREQUEST'); + $issuer = new Issuer(); + $issuer->setValue('https://sp.example.edu'); + $spRequest->setIssuer($issuer); + $decoratedSpRequest = new EngineBlock_Saml2_AuthnRequestAnnotationDecorator($spRequest); + + Phake::when($proxyServerMock) + ->getReceivedRequestFromResponse(Phake::anyParameters()) + ->thenReturn($decoratedSpRequest); + return $proxyServerMock; } @@ -261,8 +274,10 @@ private function mockSspResponse() $ebRequest->setId('EBREQUEST'); $ebRequest = new EngineBlock_Saml2_AuthnRequestAnnotationDecorator($ebRequest); - $dummySessionLog = new Psr\Log\NullLogger(); - $authnRequestRepository = new EngineBlock_Saml2_AuthnRequestSessionRepository($dummySessionLog); + $authnRequest = new \Symfony\Component\HttpFoundation\Request(); + $authnRequest->setSession(new Session(new MockArraySessionStorage())); + $testStack = new RequestStack([$authnRequest]); + $authnRequestRepository = new EngineBlock_Saml2_AuthnRequestSessionRepository($testStack); $authnRequestRepository->store($spRequest); $authnRequestRepository->store($ebRequest); $authnRequestRepository->link($ebRequest, $spRequest); diff --git a/tests/library/EngineBlock/Test/Corto/Module/Service/ProvideConsentTest.php b/tests/library/EngineBlock/Test/Corto/Module/Service/ProvideConsentTest.php index cd494032ca..ad0b48d78f 100644 --- a/tests/library/EngineBlock/Test/Corto/Module/Service/ProvideConsentTest.php +++ b/tests/library/EngineBlock/Test/Corto/Module/Service/ProvideConsentTest.php @@ -187,6 +187,19 @@ private function mockProxyServer() $bindingsModuleMock = $this->mockBindingsModule(); $proxyServerMock->setBindingsModule($bindingsModuleMock); + // Stub getReceivedRequestFromResponse so tests do not depend on DI-wired + // AuthnRequestSessionRepository being populated during the test. + $spRequest = new AuthnRequest(); + $spRequest->setId('SPREQUEST'); + $issuer = new Issuer(); + $issuer->setValue('testSp'); + $spRequest->setIssuer($issuer); + $decoratedSpRequest = new EngineBlock_Saml2_AuthnRequestAnnotationDecorator($spRequest); + + Phake::when($proxyServerMock) + ->getReceivedRequestFromResponse(Phake::anyParameters()) + ->thenReturn($decoratedSpRequest); + Phake::when($proxyServerMock) ->renderTemplate(Phake::anyParameters()) ->thenReturn(null); @@ -214,8 +227,10 @@ private function mockBindingsModule() $ebRequest->setId('EBREQUEST'); $ebRequest = new EngineBlock_Saml2_AuthnRequestAnnotationDecorator($ebRequest); - $dummyLog = new Psr\Log\NullLogger(); - $authnRequestRepository = new EngineBlock_Saml2_AuthnRequestSessionRepository($dummyLog); + $authnRequest = new \Symfony\Component\HttpFoundation\Request(); + $authnRequest->setSession(new Session(new MockArraySessionStorage())); + $testStack = new RequestStack([$authnRequest]); + $authnRequestRepository = new EngineBlock_Saml2_AuthnRequestSessionRepository($testStack); $authnRequestRepository->store($spRequest); $authnRequestRepository->store($ebRequest); $authnRequestRepository->link($ebRequest, $spRequest); diff --git a/tests/library/EngineBlock/Test/Saml2/AuthnRequestSessionRepositoryTest.php b/tests/library/EngineBlock/Test/Saml2/AuthnRequestSessionRepositoryTest.php new file mode 100644 index 0000000000..14c198eddd --- /dev/null +++ b/tests/library/EngineBlock/Test/Saml2/AuthnRequestSessionRepositoryTest.php @@ -0,0 +1,145 @@ +session = new Session(new MockArraySessionStorage()); + $requestStack = $this->createMock(RequestStack::class); + $requestStack->method('getSession')->willReturn($this->session); + $this->repo = new EngineBlock_Saml2_AuthnRequestSessionRepository($requestStack); + } + + private function makeRequest(string $id): EngineBlock_Saml2_AuthnRequestAnnotationDecorator + { + $authnRequest = new AuthnRequest(); + $authnRequest->setId($id); + return new EngineBlock_Saml2_AuthnRequestAnnotationDecorator($authnRequest); + } + + public function test_store_saves_request(): void + { + $request = $this->makeRequest('_sp-request-A'); + + $this->repo->store($request); + + $this->assertSame($request, $this->repo->findRequestById('_sp-request-A')); + } + + public function test_find_request_by_id_returns_null_for_unknown_id(): void + { + $this->assertNull($this->repo->findRequestById('_unknown')); + } + + public function test_link_stores_request_mapping(): void + { + $spRequest = $this->makeRequest('_sp-request-A'); + $idpRequest = $this->makeRequest('_idp-request-B'); + + $this->repo->store($spRequest); + $this->repo->link($idpRequest, $spRequest); + + $this->assertSame('_sp-request-A', $this->repo->findLinkedRequestId('_idp-request-B')); + } + + public function test_find_linked_request_id_returns_null_for_unknown_id(): void + { + $this->assertNull($this->repo->findLinkedRequestId('_unknown')); + } + + public function test_find_linked_request_id_returns_null_for_null_input(): void + { + $this->assertNull($this->repo->findLinkedRequestId(null)); + } + + public function test_store_and_find_multiple_requests(): void + { + $req1 = $this->makeRequest('_req-1'); + $req2 = $this->makeRequest('_req-2'); + + $this->repo->store($req1); + $this->repo->store($req2); + + $this->assertSame($req1, $this->repo->findRequestById('_req-1')); + $this->assertSame($req2, $this->repo->findRequestById('_req-2')); + } + + // ── SessionNotFoundException safety ────────────────────────────────────── + + public function test_store_is_noop_when_no_session_available(): void + { + $requestStack = $this->createMock(RequestStack::class); + $requestStack->method('getSession') + ->willThrowException(new SessionNotFoundException()); + + $repo = new EngineBlock_Saml2_AuthnRequestSessionRepository($requestStack); + $request = $this->makeRequest('_req-A'); + + $repo->store($request); // must not throw + + $this->assertNull($this->repo->findRequestById('_req-A')); + } + + public function test_link_is_noop_when_no_session_available(): void + { + $requestStack = $this->createMock(RequestStack::class); + $requestStack->method('getSession') + ->willThrowException(new SessionNotFoundException()); + + $repo = new EngineBlock_Saml2_AuthnRequestSessionRepository($requestStack); + $spRequest = $this->makeRequest('_sp-A'); + $idpRequest = $this->makeRequest('_idp-B'); + + $repo->link($idpRequest, $spRequest); // must not throw + + $this->assertNull($this->repo->findLinkedRequestId('_idp-B')); + } + + public function test_find_request_is_noop_when_no_session_available(): void + { + $requestStack = $this->createMock(RequestStack::class); + $requestStack->method('getSession') + ->willThrowException(new SessionNotFoundException()); + + $repo = new EngineBlock_Saml2_AuthnRequestSessionRepository($requestStack); + + $this->assertNull($repo->findRequestById('_req-A')); + } + + public function test_find_linked_is_noop_when_no_session_available(): void + { + $requestStack = $this->createMock(RequestStack::class); + $requestStack->method('getSession') + ->willThrowException(new SessionNotFoundException()); + + $repo = new EngineBlock_Saml2_AuthnRequestSessionRepository($requestStack); + + $this->assertNull($repo->findLinkedRequestId('_req-A')); + } +} diff --git a/tests/unit/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessorTest.php b/tests/unit/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessorTest.php new file mode 100644 index 0000000000..391ca2827f --- /dev/null +++ b/tests/unit/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessorTest.php @@ -0,0 +1,75 @@ +set('test-correlation-id'); + + $processor = new CorrelationIdProcessor($correlationId); + $record = new LogRecord( + datetime: new DateTimeImmutable(), + channel: 'test', + level: Level::Debug, + message: 'test message', + context: [], + extra: [], + ); + + $processedRecord = ($processor)($record); + + $this->assertSame('test-correlation-id', $processedRecord->extra['correlation_id']); + } + + #[Group('EngineBlock')] + #[Group('Logger')] + #[Test] + public function correlation_id_is_null_when_not_set(): void + { + $correlationId = new CurrentCorrelationId(); + + $processor = new CorrelationIdProcessor($correlationId); + $record = new LogRecord( + datetime: new DateTimeImmutable(), + channel: 'test', + level: Level::Debug, + message: 'test message', + context: [], + extra: [], + ); + + $processedRecord = ($processor)($record); + + $this->assertNull($processedRecord->extra['correlation_id']); + } +} diff --git a/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdFlowTest.php b/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdFlowTest.php new file mode 100644 index 0000000000..935e78b6f1 --- /dev/null +++ b/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdFlowTest.php @@ -0,0 +1,162 @@ +session = new Session(new MockArraySessionStorage()); + $this->requestStack = $this->createMock(RequestStack::class); + $this->requestStack->method('getSession')->willReturn($this->session); + + $this->current = new CurrentCorrelationId(); + $repository = new CorrelationIdRepository($this->requestStack); + $this->service = new CorrelationIdService($repository, $this->current); + } + + private function newService(): CorrelationIdService + { + // Each leg runs in a new request (new service instance), but shares the + // same session (same browser session). + $current = new CurrentCorrelationId(); + $repository = new CorrelationIdRepository($this->requestStack); + return new CorrelationIdService($repository, $current); + } + + private function newServiceWithCurrent(CurrentCorrelationId $current): CorrelationIdService + { + $repository = new CorrelationIdRepository($this->requestStack); + return new CorrelationIdService($repository, $current); + } + + // ── WAYF path ──────────────────────────────────────────────────────────── + + public function test_wayf_flow_all_four_legs_share_the_same_correlation_id(): void + { + $spRequestId = '_sp-request-A'; + $idpRequestId = '_idp-request-B'; + + // Leg 1 — SSO: mint the correlation ID. + $this->service->mint($spRequestId); + $this->service->resolve($spRequestId); + $mintedCx = $this->current->get(); + $this->assertNotNull($mintedCx, 'SSO must mint a correlation ID'); + + // Leg 2 — ContinueToIdp: resolves SP request ID A. + $leg2Current = new CurrentCorrelationId(); + $this->newServiceWithCurrent($leg2Current)->resolve($spRequestId); + $this->assertSame($mintedCx, $leg2Current->get(), 'ContinueToIdp must see the same correlation ID'); + + // ProxyServer links the IdP request ID to the SP request ID. + $this->service->link($idpRequestId, $spRequestId); + + // Leg 3 — ACS: IdP response InResponseTo=B, resolves via B. + $leg3Current = new CurrentCorrelationId(); + $this->newServiceWithCurrent($leg3Current)->resolve($idpRequestId); + $this->assertSame($mintedCx, $leg3Current->get(), 'ACS must see the same correlation ID'); + + // Leg 4 — Consent: resolves SP request ID A again. + $leg4Current = new CurrentCorrelationId(); + $this->newServiceWithCurrent($leg4Current)->resolve($spRequestId); + $this->assertSame($mintedCx, $leg4Current->get(), 'Consent must see the same correlation ID'); + } + + // ── Direct path (no WAYF) ───────────────────────────────────────────────── + + public function test_direct_flow_acs_and_consent_share_the_correlation_id_minted_at_sso(): void + { + $spRequestId = '_sp-direct-A'; + $idpRequestId = '_idp-direct-B'; + + $this->service->mint($spRequestId); + $this->service->link($idpRequestId, $spRequestId); + $this->service->resolve($spRequestId); + $mintedCx = $this->current->get(); + $this->assertNotNull($mintedCx); + + $ids = $this->session->get('CorrelationIds'); + $this->assertSame($mintedCx, $ids[$idpRequestId], 'ACS resolves via IdP request ID'); + $this->assertSame($mintedCx, $ids[$spRequestId], 'Consent resolves via SP request ID'); + } + + // ── Concurrent flows ────────────────────────────────────────────────────── + + public function test_two_concurrent_flows_have_independent_correlation_ids(): void + { + $this->service->mint('_sp-A1'); + $this->service->link('_idp-B1', '_sp-A1'); + + $this->service->mint('_sp-A2'); + $this->service->link('_idp-B2', '_sp-A2'); + + $ids = $this->session->get('CorrelationIds'); + $cx1 = $ids['_sp-A1']; + $cx2 = $ids['_sp-A2']; + + $this->assertNotNull($cx1); + $this->assertNotNull($cx2); + $this->assertNotSame($cx1, $cx2, 'Concurrent flows must have different correlation IDs'); + $this->assertSame($cx1, $ids['_idp-B1']); + $this->assertSame($cx2, $ids['_idp-B2']); + } + + // ── Back-button replay guard ─────────────────────────────────────────────── + + public function test_replaying_an_sso_request_does_not_change_the_correlation_id(): void + { + $spRequestId = '_sp-replay-A'; + + $this->service->mint($spRequestId); + $cx = $this->session->get('CorrelationIds')[$spRequestId]; + + $this->service->mint($spRequestId); + + $this->assertSame($cx, $this->session->get('CorrelationIds')[$spRequestId], 'Back-button replay must not change the correlation ID'); + } + + // ── Null safety ─────────────────────────────────────────────────────────── + + public function test_unknown_request_id_does_not_set_correlation_id(): void + { + $this->service->resolve('_unknown-id'); + $this->assertNull($this->current->get(), 'Correlation ID must remain null for unknown request IDs'); + } +} diff --git a/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdRepositoryTest.php b/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdRepositoryTest.php new file mode 100644 index 0000000000..44298c981e --- /dev/null +++ b/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdRepositoryTest.php @@ -0,0 +1,128 @@ +session = new Session(new MockArraySessionStorage()); + + $requestStack = $this->createMock(RequestStack::class); + $requestStack->method('getSession')->willReturn($this->session); + + $this->repo = new CorrelationIdRepository($requestStack); + } + + public function test_store_persists_correlation_id_in_session(): void + { + $cid = new CorrelationId('cx-abc123'); + + $this->repo->store('_req-A', $cid); + + $ids = $this->session->get('CorrelationIds'); + $this->assertSame('cx-abc123', $ids['_req-A']); + } + + public function test_find_returns_correlation_id_for_known_request(): void + { + $this->session->set('CorrelationIds', ['_req-A' => 'cx-abc123']); + + $result = $this->repo->find('_req-A'); + + $this->assertInstanceOf(CorrelationId::class, $result); + $this->assertSame('cx-abc123', $result->correlationId); + } + + public function test_find_returns_null_for_unknown_request(): void + { + $result = $this->repo->find('_unknown'); + + $this->assertNull($result); + } + + public function test_link_copies_correlation_id_to_target_request(): void + { + $this->session->set('CorrelationIds', ['_sp-A' => 'cx-123']); + + $this->repo->link('_idp-B', '_sp-A'); + + $this->assertSame('cx-123', $this->session->get('CorrelationIds')['_idp-B']); + } + + public function test_link_with_unknown_source_is_a_noop(): void + { + $this->repo->link('_idp-B', '_unknown'); + + $this->assertArrayNotHasKey('_idp-B', $this->session->get('CorrelationIds', [])); + } + + public function test_find_returns_stored_correlation_id(): void + { + $cid = new CorrelationId('cx-round-trip'); + $this->repo->store('_req-A', $cid); + $result = $this->repo->find('_req-A'); + $this->assertSame('cx-round-trip', $result->correlationId); + } + + public function test_store_is_noop_when_no_session_available(): void + { + $requestStack = $this->createMock(RequestStack::class); + $requestStack->method('getSession') + ->willThrowException(new SessionNotFoundException()); + + $repo = new CorrelationIdRepository($requestStack); + $repo->store('_req-A', new CorrelationId('cx-123')); + + // No exception thrown — that's the assertion + $this->expectNotToPerformAssertions(); + } + + public function test_find_returns_null_when_no_session_available(): void + { + $requestStack = $this->createMock(RequestStack::class); + $requestStack->method('getSession') + ->willThrowException(new SessionNotFoundException()); + + $repo = new CorrelationIdRepository($requestStack); + + $this->assertNull($repo->find('_req-A')); + } + + public function test_link_is_noop_when_no_session_available(): void + { + $requestStack = $this->createMock(RequestStack::class); + $requestStack->method('getSession') + ->willThrowException(new SessionNotFoundException()); + + $repo = new CorrelationIdRepository($requestStack); + $repo->link('_idp-B', '_sp-A'); + + $this->assertNull($this->session->get('CorrelationIds')); + } +} diff --git a/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdServiceTest.php b/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdServiceTest.php new file mode 100644 index 0000000000..b1ca470ad3 --- /dev/null +++ b/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdServiceTest.php @@ -0,0 +1,103 @@ +session = new Session(new MockArraySessionStorage()); + + $requestStack = $this->createMock(RequestStack::class); + $requestStack->method('getSession')->willReturn($this->session); + + $this->repository = new CorrelationIdRepository($requestStack); + $this->current = new CurrentCorrelationId(); + $this->service = new CorrelationIdService($this->repository, $this->current); + } + + public function test_mint_stores_a_new_correlation_id_when_none_exists(): void + { + $this->service->mint('_req-A'); + + $ids = $this->session->get('CorrelationIds'); + $this->assertArrayHasKey('_req-A', $ids); + $this->assertNotEmpty($ids['_req-A']); + } + + public function test_mint_does_not_overwrite_when_one_already_exists(): void + { + $this->session->set('CorrelationIds', ['_req-A' => 'cx-existing']); + + $this->service->mint('_req-A'); + + $this->assertSame('cx-existing', $this->session->get('CorrelationIds')['_req-A']); + } + + public function test_link_copies_correlation_id_to_target(): void + { + $this->session->set('CorrelationIds', ['_sp-A' => 'cx-123']); + + $this->service->link('_idp-B', '_sp-A'); + + $this->assertSame('cx-123', $this->session->get('CorrelationIds')['_idp-B']); + } + + public function test_resolve_sets_current_correlation_id_when_found(): void + { + $this->session->set('CorrelationIds', ['_req-A' => 'cx-abc123']); + + $this->service->resolve('_req-A'); + + $this->assertSame('cx-abc123', $this->current->get()); + } + + public function test_resolve_does_not_change_current_when_not_found(): void + { + $this->service->resolve('_unknown'); + + $this->assertNull($this->current->get()); + } + + public function test_resolve_with_null_is_a_noop(): void + { + $this->service->resolve(null); + + $this->assertNull($this->current->get()); + } + + public function test_mint_then_resolve_sets_current_correlation_id(): void + { + $this->service->mint('_req-A'); + $this->service->resolve('_req-A'); + + $this->assertNotNull($this->current->get()); + $this->assertNotEmpty($this->current->get()); + } +} From daf0c2cbe3a3924b4a9ec867fd87fffac9fb85c1 Mon Sep 17 00:00:00 2001 From: Kay Joosten Date: Tue, 21 Apr 2026 18:25:37 +0200 Subject: [PATCH 4/8] fix: restore accidentally removed services.yml arguments --- config/services/services.yml | 2 ++ 1 file changed, 2 insertions(+) diff --git a/config/services/services.yml b/config/services/services.yml index b45b6ae307..11843e07aa 100644 --- a/config/services/services.yml +++ b/config/services/services.yml @@ -18,6 +18,7 @@ services: class: OpenConext\EngineBlockBundle\HealthCheck\DoctrineConnectionHealthCheck arguments: - '%monitor_database_health_check_query%' + - '@logger' calls: - [ setEntityManager, ['@?doctrine.orm.entity_manager']] tags: @@ -171,6 +172,7 @@ services: - '@OpenConext\EngineBlock\Xml\DocumentSigner' - '@OpenConext\EngineBlock\Service\TimeProvider\TimeProvider' - '%metadata_add_requested_attributes%' + - "%metadata_expiration_time%" OpenConext\EngineBlock\Xml\MetadataProvider: arguments: From fd8f802c28c096518ada9e6ce4c5e397cafa6d77 Mon Sep 17 00:00:00 2001 From: Kay Joosten Date: Tue, 21 Apr 2026 18:31:02 +0200 Subject: [PATCH 5/8] fix: remove log-assertion steps that cannot work with external web server --- .../Features/CorrelationId.feature | 2 -- 1 file changed, 2 deletions(-) diff --git a/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/CorrelationId.feature b/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/CorrelationId.feature index aca0a65f8c..874c1d2953 100644 --- a/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/CorrelationId.feature +++ b/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/CorrelationId.feature @@ -26,7 +26,6 @@ Feature: And I give my consent And I pass through EngineBlock Then the url should match "functional-testing/CorrId-SP/acs" - And each log record should contain a "correlation_id" field # ── Direct path (no WAYF) ─────────────────────────────────────────────────── # When only one IdP is available the WAYF is skipped; the correlation ID is @@ -41,7 +40,6 @@ Feature: And I give my consent And I pass through EngineBlock Then the url should match "functional-testing/CorrId-SP/acs" - And each log record should contain a "correlation_id" field # ── Concurrent flows ──────────────────────────────────────────────────────── # Two simultaneous authentications in separate browser tabs share the same PHP From 3c4b4f215fbd1d0ecb79e9d044dc86c3014a4e5c Mon Sep 17 00:00:00 2001 From: Kay Joosten Date: Tue, 21 Apr 2026 19:47:11 +0200 Subject: [PATCH 6/8] style: remove inline docblocks, fix copyright year to 2026 on new files --- .../Processor/CorrelationIdProcessor.php | 2 +- .../EngineBlock/Request/CorrelationId.php | 5 +--- .../Request/CorrelationIdRepository.php | 26 +------------------ .../Request/CorrelationIdService.php | 25 +----------------- .../Request/CurrentCorrelationId.php | 7 +---- .../Features/Context/LoggingContext.php | 11 +------- .../Log/TestLogHandler.php | 16 +----------- 7 files changed, 7 insertions(+), 85 deletions(-) diff --git a/src/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessor.php b/src/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessor.php index 8b190f04c0..108d56943c 100644 --- a/src/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessor.php +++ b/src/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessor.php @@ -1,7 +1,7 @@ set(self::SESSION_KEY, $ids); } - /** - * Copies the correlation ID from $sourceRequestId to $targetRequestId. - * No-op when source is not found or no session is available. - */ public function link(string $targetRequestId, string $sourceRequestId): void { try { @@ -80,10 +60,6 @@ public function link(string $targetRequestId, string $sourceRequestId): void $session->set(self::SESSION_KEY, $ids); } - /** - * Returns the CorrelationId for $requestId, or null when not found. - * Returns null when no session is available. - */ public function find(string $requestId): ?CorrelationId { try { diff --git a/src/OpenConext/EngineBlock/Request/CorrelationIdService.php b/src/OpenConext/EngineBlock/Request/CorrelationIdService.php index 66d10bb481..11a3de2397 100644 --- a/src/OpenConext/EngineBlock/Request/CorrelationIdService.php +++ b/src/OpenConext/EngineBlock/Request/CorrelationIdService.php @@ -1,7 +1,7 @@ repository->find($requestId) === null) { @@ -48,19 +33,11 @@ public function mint(string $requestId): void } } - /** - * Copies the correlation ID from $sourceRequestId to $targetRequestId. - */ public function link(string $targetRequestId, string $sourceRequestId): void { $this->repository->link($targetRequestId, $sourceRequestId); } - /** - * Looks up the correlation ID for $requestId and sets it as the active ID - * in CurrentCorrelationId so all subsequent log entries carry it. - * No-op when $requestId is null or not found. - */ public function resolve(?string $requestId): void { if ($requestId === null) { diff --git a/src/OpenConext/EngineBlock/Request/CurrentCorrelationId.php b/src/OpenConext/EngineBlock/Request/CurrentCorrelationId.php index f50add505b..dab1b3b91d 100644 --- a/src/OpenConext/EngineBlock/Request/CurrentCorrelationId.php +++ b/src/OpenConext/EngineBlock/Request/CurrentCorrelationId.php @@ -1,7 +1,7 @@ records[] = $record; } - /** - * Returns all captured log records since the last reset. - * - * @return LogRecord[] - */ public function getRecords(): array { return $this->records; } - /** - * Clears all captured log records. - */ public function reset(): void { $this->records = []; From e5e4d1f5d7eb58d4ac7f5e1a3eba913b764b77c3 Mon Sep 17 00:00:00 2001 From: Kay Joosten Date: Wed, 22 Apr 2026 12:15:58 +0200 Subject: [PATCH 7/8] refactor: replace CurrentCorrelationId getter/setter with public property --- library/EngineBlock/Application/DiContainer.php | 7 ++++--- .../Corto/Module/Service/ContinueToIdp.php | 14 ++++---------- .../Corto/Module/Service/SingleSignOn.php | 15 ++++++++------- library/EngineBlock/Corto/ProxyServer.php | 14 +++++--------- .../Logger/Processor/CorrelationIdProcessor.php | 2 +- .../EngineBlock/Request/CorrelationId.php | 2 +- .../EngineBlock/Request/CorrelationIdService.php | 2 +- .../EngineBlock/Request/CurrentCorrelationId.php | 12 +----------- .../Processor/CorrelationIdProcessorTest.php | 2 +- .../EngineBlock/Request/CorrelationIdFlowTest.php | 12 ++++++------ .../Request/CorrelationIdServiceTest.php | 10 +++++----- 11 files changed, 37 insertions(+), 55 deletions(-) diff --git a/library/EngineBlock/Application/DiContainer.php b/library/EngineBlock/Application/DiContainer.php index 79ff6486fe..76068e4841 100644 --- a/library/EngineBlock/Application/DiContainer.php +++ b/library/EngineBlock/Application/DiContainer.php @@ -20,6 +20,7 @@ use OpenConext\EngineBlock\Metadata\Factory\Factory\ServiceProviderFactory; use OpenConext\EngineBlock\Metadata\LoaRepository; use OpenConext\EngineBlock\Metadata\MetadataRepository\MetadataRepositoryInterface; +use OpenConext\EngineBlock\Request\CorrelationIdService; use OpenConext\EngineBlock\Service\MfaHelperInterface; use OpenConext\EngineBlock\Service\ReleaseAsEnforcer; use OpenConext\EngineBlock\Service\TimeProvider\TimeProviderInterface; @@ -615,11 +616,11 @@ public function getNameIdSubstituteResolver() } /** - * @return \OpenConext\EngineBlock\Request\CorrelationIdService + * @return CorrelationIdService */ - public function getCorrelationIdService(): \OpenConext\EngineBlock\Request\CorrelationIdService + public function getCorrelationIdService(): CorrelationIdService { - return $this->container->get(\OpenConext\EngineBlock\Request\CorrelationIdService::class); + return $this->container->get(CorrelationIdService::class); } /** diff --git a/library/EngineBlock/Corto/Module/Service/ContinueToIdp.php b/library/EngineBlock/Corto/Module/Service/ContinueToIdp.php index 1865759fe9..abd5a2c8f1 100644 --- a/library/EngineBlock/Corto/Module/Service/ContinueToIdp.php +++ b/library/EngineBlock/Corto/Module/Service/ContinueToIdp.php @@ -85,9 +85,9 @@ public function serve($serviceName, Request $httpRequest) ); } - $authnRequestRepository = EngineBlock_ApplicationSingleton::getInstance() - ->getDiContainer() - ->getAuthnRequestSessionRepository(); + $container = EngineBlock_ApplicationSingleton::getInstance()->getDiContainer(); + + $authnRequestRepository = $container->getAuthnRequestSessionRepository(); $request = $authnRequestRepository->findRequestById($id); if (!$request) { @@ -96,13 +96,7 @@ public function serve($serviceName, Request $httpRequest) ); } - // Resolve here so log entries emitted during this leg carry the correlation ID. - // ProxyServer::sendAuthenticationRequest will also call mint()+link()+resolve() - // on the SP request ID — that is idempotent and sets the same value. - // The IdP request ID is only resolvable in AssertionConsumer (Leg 3). - $correlationIdService = EngineBlock_ApplicationSingleton::getInstance() - ->getDiContainer() - ->getCorrelationIdService(); + $correlationIdService = $container->getCorrelationIdService(); $correlationIdService->resolve($id); // Flush log if SP or IdP has additional logging enabled diff --git a/library/EngineBlock/Corto/Module/Service/SingleSignOn.php b/library/EngineBlock/Corto/Module/Service/SingleSignOn.php index 8d769e847c..b25245bd4f 100644 --- a/library/EngineBlock/Corto/Module/Service/SingleSignOn.php +++ b/library/EngineBlock/Corto/Module/Service/SingleSignOn.php @@ -73,6 +73,7 @@ public function __construct( public function serve($serviceName, Request $httpRequest) { $application = EngineBlock_ApplicationSingleton::getInstance(); + $container = $application->getDiContainer(); $log = $this->_server->getLogger(); @@ -202,9 +203,9 @@ public function serve($serviceName, Request $httpRequest) // Multiple IdPs found... // Auto-select IdP when 'feature_enable_sso_notification' is enabled and send AuthenticationRequest on success - if ($application->getDiContainer()->getFeatureConfiguration()->isEnabled("eb.enable_sso_notification")) { - $idpEntityId = $application->getDiContainer()->getSsoNotificationService()-> - handleSsoNotification($application->getDiContainer()->getSymfonyRequest()->cookies, $this->_server); + if ($container->getFeatureConfiguration()->isEnabled("eb.enable_sso_notification")) { + $idpEntityId = $container->getSsoNotificationService()-> + handleSsoNotification($container->getSymfonyRequest()->cookies, $this->_server); if (!empty($idpEntityId)) { try { @@ -220,8 +221,8 @@ public function serve($serviceName, Request $httpRequest) } // Auto-select IdP when 'wayf.rememberChoice' feature is enabled and is allowed for the current request - if (($application->getDiContainer()->getRememberChoice() === true) && !($request->getForceAuthn() || $request->isDebugRequest())) { - $cookies = $application->getDiContainer()->getSymfonyRequest()->cookies->all(); + if (($container->getRememberChoice() === true) && !($request->getForceAuthn() || $request->isDebugRequest())) { + $cookies = $container->getSymfonyRequest()->cookies->all(); if (array_key_exists('rememberchoice', $cookies)) { $remembered = json_decode($cookies['rememberchoice']); if (array_search($remembered, $candidateIDPs) !== false) { @@ -240,10 +241,10 @@ public function serve($serviceName, Request $httpRequest) return; } - $authnRequestRepository = $application->getDiContainer()->getAuthnRequestSessionRepository(); + $authnRequestRepository = $container->getAuthnRequestSessionRepository(); $authnRequestRepository->store($request); - $correlationIdService = $application->getDiContainer()->getCorrelationIdService(); + $correlationIdService = $container->getCorrelationIdService(); $correlationIdService->mint($request->getId()); $correlationIdService->resolve($request->getId()); diff --git a/library/EngineBlock/Corto/ProxyServer.php b/library/EngineBlock/Corto/ProxyServer.php index 529dbb10dc..21d09d3b90 100644 --- a/library/EngineBlock/Corto/ProxyServer.php +++ b/library/EngineBlock/Corto/ProxyServer.php @@ -461,21 +461,17 @@ public function sendAuthenticationRequest( } } - $authenticationState = EngineBlock_ApplicationSingleton::getInstance()->getDiContainer() - ->getAuthenticationStateHelper() - ->getAuthenticationState(); + $container = EngineBlock_ApplicationSingleton::getInstance()->getDiContainer(); + + $authenticationState = $container->getAuthenticationStateHelper()->getAuthenticationState(); $authenticationState->startAuthenticationOnBehalfOf($ebRequest->getId(), $serviceProvider); // Store the original Request - $authnRequestRepository = EngineBlock_ApplicationSingleton::getInstance() - ->getDiContainer() - ->getAuthnRequestSessionRepository(); + $authnRequestRepository = $container->getAuthnRequestSessionRepository(); $authnRequestRepository->store($spRequest); $authnRequestRepository->link($ebRequest, $spRequest); - $correlationIdService = EngineBlock_ApplicationSingleton::getInstance() - ->getDiContainer() - ->getCorrelationIdService(); + $correlationIdService = $container->getCorrelationIdService(); $correlationIdService->mint($spRequest->getId()); $correlationIdService->link($ebRequest->getId(), $spRequest->getId()); $correlationIdService->resolve($spRequest->getId()); diff --git a/src/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessor.php b/src/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessor.php index 108d56943c..f73ec48a33 100644 --- a/src/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessor.php +++ b/src/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessor.php @@ -30,7 +30,7 @@ public function __construct(private readonly CurrentCorrelationId $correlationId public function __invoke(LogRecord $record): LogRecord { - $record->extra['correlation_id'] = $this->correlationId->get(); + $record->extra['correlation_id'] = $this->correlationId->correlationId; return $record; } diff --git a/src/OpenConext/EngineBlock/Request/CorrelationId.php b/src/OpenConext/EngineBlock/Request/CorrelationId.php index 49ec4ec9d4..50b30cd242 100644 --- a/src/OpenConext/EngineBlock/Request/CorrelationId.php +++ b/src/OpenConext/EngineBlock/Request/CorrelationId.php @@ -26,6 +26,6 @@ public function __construct(public readonly string $correlationId) public static function mint(): self { - return new self(bin2hex(random_bytes(16))); + return new self(bin2hex(random_bytes(8))); } } diff --git a/src/OpenConext/EngineBlock/Request/CorrelationIdService.php b/src/OpenConext/EngineBlock/Request/CorrelationIdService.php index 11a3de2397..e7c94f7db7 100644 --- a/src/OpenConext/EngineBlock/Request/CorrelationIdService.php +++ b/src/OpenConext/EngineBlock/Request/CorrelationIdService.php @@ -47,7 +47,7 @@ public function resolve(?string $requestId): void $cid = $this->repository->find($requestId); if ($cid !== null) { - $this->current->set($cid->correlationId); + $this->current->correlationId = $cid->correlationId; } } } diff --git a/src/OpenConext/EngineBlock/Request/CurrentCorrelationId.php b/src/OpenConext/EngineBlock/Request/CurrentCorrelationId.php index dab1b3b91d..c4c50a0a24 100644 --- a/src/OpenConext/EngineBlock/Request/CurrentCorrelationId.php +++ b/src/OpenConext/EngineBlock/Request/CurrentCorrelationId.php @@ -20,15 +20,5 @@ final class CurrentCorrelationId { - private ?string $correlationId = null; - - public function set(string $correlationId): void - { - $this->correlationId = $correlationId; - } - - public function get(): ?string - { - return $this->correlationId; - } + public ?string $correlationId = null; } diff --git a/tests/unit/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessorTest.php b/tests/unit/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessorTest.php index 391ca2827f..e015f32287 100644 --- a/tests/unit/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessorTest.php +++ b/tests/unit/OpenConext/EngineBlock/Logger/Processor/CorrelationIdProcessorTest.php @@ -34,7 +34,7 @@ class CorrelationIdProcessorTest extends TestCase public function correlation_id_is_added_to_the_record(): void { $correlationId = new CurrentCorrelationId(); - $correlationId->set('test-correlation-id'); + $correlationId->correlationId = 'test-correlation-id'; $processor = new CorrelationIdProcessor($correlationId); $record = new LogRecord( diff --git a/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdFlowTest.php b/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdFlowTest.php index 935e78b6f1..af21f8a25f 100644 --- a/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdFlowTest.php +++ b/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdFlowTest.php @@ -77,13 +77,13 @@ public function test_wayf_flow_all_four_legs_share_the_same_correlation_id(): vo // Leg 1 — SSO: mint the correlation ID. $this->service->mint($spRequestId); $this->service->resolve($spRequestId); - $mintedCx = $this->current->get(); + $mintedCx = $this->current->correlationId; $this->assertNotNull($mintedCx, 'SSO must mint a correlation ID'); // Leg 2 — ContinueToIdp: resolves SP request ID A. $leg2Current = new CurrentCorrelationId(); $this->newServiceWithCurrent($leg2Current)->resolve($spRequestId); - $this->assertSame($mintedCx, $leg2Current->get(), 'ContinueToIdp must see the same correlation ID'); + $this->assertSame($mintedCx, $leg2Current->correlationId, 'ContinueToIdp must see the same correlation ID'); // ProxyServer links the IdP request ID to the SP request ID. $this->service->link($idpRequestId, $spRequestId); @@ -91,12 +91,12 @@ public function test_wayf_flow_all_four_legs_share_the_same_correlation_id(): vo // Leg 3 — ACS: IdP response InResponseTo=B, resolves via B. $leg3Current = new CurrentCorrelationId(); $this->newServiceWithCurrent($leg3Current)->resolve($idpRequestId); - $this->assertSame($mintedCx, $leg3Current->get(), 'ACS must see the same correlation ID'); + $this->assertSame($mintedCx, $leg3Current->correlationId, 'ACS must see the same correlation ID'); // Leg 4 — Consent: resolves SP request ID A again. $leg4Current = new CurrentCorrelationId(); $this->newServiceWithCurrent($leg4Current)->resolve($spRequestId); - $this->assertSame($mintedCx, $leg4Current->get(), 'Consent must see the same correlation ID'); + $this->assertSame($mintedCx, $leg4Current->correlationId, 'Consent must see the same correlation ID'); } // ── Direct path (no WAYF) ───────────────────────────────────────────────── @@ -109,7 +109,7 @@ public function test_direct_flow_acs_and_consent_share_the_correlation_id_minted $this->service->mint($spRequestId); $this->service->link($idpRequestId, $spRequestId); $this->service->resolve($spRequestId); - $mintedCx = $this->current->get(); + $mintedCx = $this->current->correlationId; $this->assertNotNull($mintedCx); $ids = $this->session->get('CorrelationIds'); @@ -157,6 +157,6 @@ public function test_replaying_an_sso_request_does_not_change_the_correlation_id public function test_unknown_request_id_does_not_set_correlation_id(): void { $this->service->resolve('_unknown-id'); - $this->assertNull($this->current->get(), 'Correlation ID must remain null for unknown request IDs'); + $this->assertNull($this->current->correlationId, 'Correlation ID must remain null for unknown request IDs'); } } diff --git a/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdServiceTest.php b/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdServiceTest.php index b1ca470ad3..a7b8d7cee0 100644 --- a/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdServiceTest.php +++ b/tests/unit/OpenConext/EngineBlock/Request/CorrelationIdServiceTest.php @@ -75,21 +75,21 @@ public function test_resolve_sets_current_correlation_id_when_found(): void $this->service->resolve('_req-A'); - $this->assertSame('cx-abc123', $this->current->get()); + $this->assertSame('cx-abc123', $this->current->correlationId); } public function test_resolve_does_not_change_current_when_not_found(): void { $this->service->resolve('_unknown'); - $this->assertNull($this->current->get()); + $this->assertNull($this->current->correlationId); } public function test_resolve_with_null_is_a_noop(): void { $this->service->resolve(null); - $this->assertNull($this->current->get()); + $this->assertNull($this->current->correlationId); } public function test_mint_then_resolve_sets_current_correlation_id(): void @@ -97,7 +97,7 @@ public function test_mint_then_resolve_sets_current_correlation_id(): void $this->service->mint('_req-A'); $this->service->resolve('_req-A'); - $this->assertNotNull($this->current->get()); - $this->assertNotEmpty($this->current->get()); + $this->assertNotNull($this->current->correlationId); + $this->assertNotEmpty($this->current->correlationId); } } From baad08de320803d203a44f0e0d34274809a7dba2 Mon Sep 17 00:00:00 2001 From: Johan Kromhout Date: Thu, 23 Apr 2026 14:21:11 +0200 Subject: [PATCH 8/8] WIP - ???Actually check logs??? --- config/packages/ci/monolog.yaml | 5 + config/services_ci.yaml | 5 + .../Features/Context/LoggingContext.php | 134 +++++++++++++---- .../Features/CorrelationId.feature | 141 ++++++++++++------ tests/behat.yml | 2 +- .../AuthnRequestSessionRepositoryTest.php | 2 +- .../Processor/CorrelationIdProcessorTest.php | 2 +- .../Request/CorrelationIdFlowTest.php | 2 +- .../Request/CorrelationIdRepositoryTest.php | 2 +- .../Request/CorrelationIdServiceTest.php | 2 +- 10 files changed, 218 insertions(+), 79 deletions(-) diff --git a/config/packages/ci/monolog.yaml b/config/packages/ci/monolog.yaml index 6753119973..0f06c90ad8 100644 --- a/config/packages/ci/monolog.yaml +++ b/config/packages/ci/monolog.yaml @@ -3,3 +3,8 @@ monolog: test_log_handler: type: service id: OpenConext\EngineBlockFunctionalTestingBundle\Log\TestLogHandler + test_log_file: + type: stream + path: '/tmp/eb-fixtures/log-records.ndjson' + level: debug + formatter: monolog.formatter.json diff --git a/config/services_ci.yaml b/config/services_ci.yaml index 74d2666f86..dc786dda76 100644 --- a/config/services_ci.yaml +++ b/config/services_ci.yaml @@ -68,6 +68,11 @@ services: OpenConext\EngineBlockFunctionalTestingBundle\Features\Context\MinkContext: tags: ['fob.context'] + OpenConext\EngineBlockFunctionalTestingBundle\Features\Context\LoggingContext: + arguments: + $logFile: '/tmp/eb-fixtures/log-records.ndjson' + tags: ['fob.context'] + OpenConext\EngineBlockFunctionalTestingBundle\Fixtures\SbsClientStateManager: arguments: - "@engineblock.functional_testing.data_store.sbs_client_state_mananger" diff --git a/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/Context/LoggingContext.php b/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/Context/LoggingContext.php index ba592ac617..3daeec8043 100644 --- a/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/Context/LoggingContext.php +++ b/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/Context/LoggingContext.php @@ -19,12 +19,12 @@ namespace OpenConext\EngineBlockFunctionalTestingBundle\Features\Context; use Behat\Behat\Context\Context; -use OpenConext\EngineBlockFunctionalTestingBundle\Log\TestLogHandler; -use PHPUnit\Framework\Assert; +use Behat\Gherkin\Node\TableNode; +use RuntimeException; class LoggingContext implements Context { - public function __construct(private readonly TestLogHandler $logHandler) + public function __construct(private readonly string $logFile) { } @@ -33,41 +33,115 @@ public function __construct(private readonly TestLogHandler $logHandler) */ public function resetLogHandler(): void { - $this->logHandler->reset(); + file_put_contents($this->logFile, ''); } /** - * @Then each log record should contain a :field field + * @Then the following log messages should have a correlation_id: */ - public function eachLogRecordShouldContainField(string $field): void + public function theFollowingLogMessagesShouldHaveACorrelationId(TableNode $table): void { - $records = $this->logHandler->getRecords(); - - Assert::assertNotEmpty($records, 'No log records were captured during this scenario.'); - - foreach ($records as $index => $record) { - Assert::assertArrayHasKey( - $field, - $record->extra, - sprintf( - 'Log record #%d (channel=%s, message="%s") is missing extra field "%s".', - $index, - $record->channel, - $record->message, - $field, - ), + $records = $this->readRecords(); + $allCorrelationIds = []; + + foreach ($table->getColumnsHash() as $row) { + $pattern = $row['message']; + $isRegex = preg_match('/^\/.*\/$/', $pattern) === 1; + + $matched = array_filter( + $records, + static fn(array $r) => $isRegex + ? preg_match($pattern, $r['message'] ?? '') === 1 + : ($r['message'] ?? '') === $pattern, ); - Assert::assertNotNull( - $record->extra[$field], - sprintf( - 'Log record #%d (channel=%s, message="%s") has a null value for extra field "%s".', - $index, - $record->channel, - $record->message, - $field, - ), + if (empty($matched)) { + throw new RuntimeException(sprintf( + 'No log record matched message %s "%s".', + $isRegex ? 'pattern' : 'string', + $pattern, + )); + } + + foreach ($matched as $record) { + $correlationId = $record['extra']['correlation_id'] ?? null; + + if ($correlationId === null) { + throw new RuntimeException(sprintf( + 'Log record matching "%s" (channel=%s) has a null correlation_id.', + $pattern, + $record['channel'] ?? '?', + )); + } + + $allCorrelationIds[] = $correlationId; + } + } + + $distinct = array_unique($allCorrelationIds); + + if (count($distinct) > 1) { + throw new RuntimeException(sprintf( + 'Expected a single correlation_id across all matched log records, but found %d distinct values: %s.', + count($distinct), + implode(', ', $distinct), + )); + } + } + + /** + * @Then I dump the log records + */ + public function iDumpTheLogRecords(): void + { + $records = $this->readRecords(); + $rows = []; + foreach ($records as $record) { + $message = $record['message'] ?? ''; + if (mb_strlen($message) > 100) { + $message = mb_substr($message, 0, 97) . '...'; + } + $rows[] = sprintf( + '| %-12s | %-9s | %-100s | %s |', + $record['channel'] ?? '', + $record['level_name'] ?? '', + str_replace('|', '\\|', $message), + $record['extra']['correlation_id'] ?? 'null', ); } + echo "\n" . implode("\n", $rows) . "\n"; + } + + /** + * Reads all records from the log file, decodes each JSON line, and returns only + * records not belonging to the event channel (Symfony kernel internals). + * + * @return array> + */ + private function readRecords(): array + { + $lines = file($this->logFile, FILE_IGNORE_NEW_LINES | FILE_SKIP_EMPTY_LINES); + + if ($lines === false) { + return []; + } + + $records = []; + + foreach ($lines as $index => $line) { + $record = json_decode($line, true); + + if (!is_array($record)) { + throw new RuntimeException(sprintf('Log record #%d could not be decoded as JSON.', $index)); + } + + if (($record['channel'] ?? '') === 'event') { + continue; + } + + $records[] = $record; + } + + return $records; } } diff --git a/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/CorrelationId.feature b/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/CorrelationId.feature index 874c1d2953..fc4070af06 100644 --- a/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/CorrelationId.feature +++ b/src/OpenConext/EngineBlockFunctionalTestingBundle/Features/CorrelationId.feature @@ -5,63 +5,118 @@ Feature: Background: Given an EngineBlock instance on "dev.openconext.local" - And no registered SPs - And no registered Idps - And a Service Provider named "CorrId-SP" + And no registered SPs + And no registered Idps + And a Service Provider named "CorrId-SP" - # ── WAYF path ────────────────────────────────────────────────────────────── - # Two IdPs are registered, so the WAYF is shown after the initial SSO request. - # The correlation ID is minted in SingleSignOn.serve(), propagated to - # ContinueToIdp (user picks an IdP), then forwarded to the IdP request via - # link(), and finally picked up in AssertionConsumer and ProvideConsent/ - # ProcessConsent. A complete round-trip through all four HTTP legs must - # succeed without error. Scenario: A user authenticating via the WAYF completes the full four-leg flow Given an Identity Provider named "CorrId-IdP-A" - And an Identity Provider named "CorrId-IdP-B" + And an Identity Provider named "CorrId-IdP-B" When I log in at "CorrId-SP" - And I select "CorrId-IdP-A" on the WAYF - And I pass through EngineBlock - And I pass through the IdP - And I give my consent - And I pass through EngineBlock + And I select "CorrId-IdP-A" on the WAYF + And I pass through EngineBlock + And I pass through the IdP + And I give my consent + And I pass through EngineBlock Then the url should match "functional-testing/CorrId-SP/acs" + #And I dump the log records + And the following log messages should have a correlation_id: + | message | + | Multiple candidate IdPs: redirecting to WAYF | + | Done calling service 'singleSignOnService' | + | Done calling service 'continueToIdp' | + | /Received Assertion from Issuer .*/ | + | /SP is not configured for MFA for IdP, or for transparant AuthnContext, skipping validation .*/ | + | Verifying if schacHomeOrganization is allowed by configured IdP shibmd:scopes | + | No shibmd:scope found in the IdP metadata, not verifying schacHomeOrganization | + | Verifying if eduPersonPrincipalName is allowed by configured IdP shibmd:scopes | + | No shibmd:scope found in the IdP metadata, not verifying eduPersonPrincipalName | + | Verifying if subject-id is allowed by configured IdP shibmd:scopes | + | No shibmd:scope found in the IdP metadata, not verifying subject-id | + | /No Attribute Aggregation for .*/ | + | /No SBS interrupt for serviceProvider.*/ | + | StepupDecision: determine highest LoA | + | StepupDecision: no level set, no Stepup required | + | Handle Consent authentication callout | + | Using internal binding for destination /authentication/idp/provide-consent | + | Calling service 'provideConsentService' | + | Done calling service 'provideConsentService' | + | Done calling service 'assertionConsumerService' | + | /Using internal binding for destination https:\/\/engine.dev.openconext.local\/authenticati.*/ | + | Calling service 'processedAssertionConsumerService' | + | /No ARP available for https:\/\/engine.dev.openconext.local\/functional-testing\/CorrId-SP\/metadata. .*/ | + | Executing the ApplyTrustedProxyBehavior output filter | + | Executing the AddIdentityAttributes output filter | + | Resolving a persistent nameId | + | Setting the NameId on the Assertion | + | Adding the EduPersonTargetedId on the Assertion | + | /Attribute Denormalization: Adding alias 'urn:oid:0.9.2342.19200300.100.1.1' .*/ | + | /Attribute Denormalization: Adding alias 'urn:oid:1.3.6.1.4.1.25178.1.2.9' for .*/ | + | /Attribute Denormalization: Adding alias 'urn:oid:1.3.6.1.4.1.5923.1.1.1.10' for .*/ | + | HTTP-Post: Sending Message | + | Done calling service 'processedAssertionConsumerService' | + | Done calling service 'processConsentService' | - # ── Direct path (no WAYF) ─────────────────────────────────────────────────── - # When only one IdP is available the WAYF is skipped; the correlation ID is - # minted inside ProxyServer.sendAuthenticationRequest() and linked to the IdP - # request. AssertionConsumer and consent legs must resolve it from the IdP - # request ID stored in InResponseTo. Scenario: A user authenticating without the WAYF completes the full flow Given an Identity Provider named "CorrId-IdP-Only" When I log in at "CorrId-SP" - And I pass through EngineBlock - And I pass through the IdP - And I give my consent - And I pass through EngineBlock + And I pass through EngineBlock + And I pass through the IdP + And I give my consent + And I pass through EngineBlock Then the url should match "functional-testing/CorrId-SP/acs" + And I dump the log records + And the following log messages should have a correlation_id: + | message | + | HTTP-Post: Sending Message | + | Done calling service 'singleSignOnService' | + | /SP is not configured for MFA for IdP, or for transparant AuthnContext, skipping validation of .*/ | + | Verifying if schacHomeOrganization is allowed by configured IdP shibmd:scopes | + | No shibmd:scope found in the IdP metadata, not verifying schacHomeOrganization | + | Verifying if eduPersonPrincipalName is allowed by configured IdP shibmd:scopes | + | No shibmd:scope found in the IdP metadata, not verifying eduPersonPrincipalName | + | Verifying if subject-id is allowed by configured IdP shibmd:scopes | + | No shibmd:scope found in the IdP metadata, not verifying subject-id | + | /No Attribute Aggregation for https:\/\/engine.dev.openconext.local\/functional-testing\/CorrId-S.*/ | + | /No SBS interrupt for serviceProvider: https:\/\/engine.dev.openconext.local\/functional-testin.*/ | + | StepupDecision: determine highest LoA | + | StepupDecision: no level set, no Stepup required | + | Handle Consent authentication callout | + | Using internal binding for destination /authentication/idp/provide-consent | + | Calling service 'provideConsentService' | + | Done calling service 'provideConsentService' | + | Done calling service 'assertionConsumerService' | + | /Using internal binding for destination.*/ | + | Calling service 'processedAssertionConsumerService' | + | /No ARP available for https:\/\/engine.dev.openconext.local\/functional-testing\/CorrId-SP\/metadata. */ | + | Executing the ApplyTrustedProxyBehavior output filter | + | Executing the AddIdentityAttributes output filter | + | Resolving a persistent nameId | + | Setting the NameId on the Assertion | + | Adding the EduPersonTargetedId on the Assertion | + | /Attribute Denormalization: Adding alias 'urn:oid:0.9.2342.19200300.100.1.1'*/ | + | /Attribute Denormalization: Adding alias 'urn:oid:1.3.6.1.4.1.25178.1.2.9' f*/ | + | /Attribute Denormalization: Adding alias 'urn:oid:1.3.6.1.4.1.5923.1.1.1.10' */ | + | login granted | + | HTTP-Post: Sending Message | + | Done calling service 'processedAssertionConsumerService' | + | Done calling service 'processConsentService' | - # ── Concurrent flows ──────────────────────────────────────────────────────── - # Two simultaneous authentications in separate browser tabs share the same PHP - # session. Each flow must mint its own correlation ID and the two IDs must - # not bleed into each other. Both flows must complete successfully and land - # on the correct SP ACS URL. - # Requires the @functional tag to use the Chrome driver (browser tabs need JS). @functional Scenario: Two concurrent authentication flows each complete independently Given an Identity Provider named "CorrId-IdP-A" - And an Identity Provider named "CorrId-IdP-B" + And an Identity Provider named "CorrId-IdP-B" When I open 2 browser tabs identified by "Tab-A, Tab-B" - And I switch to "Tab-A" - And I log in at "CorrId-SP" - And I select "CorrId-IdP-A" on the WAYF - And I switch to "Tab-B" - And I log in at "CorrId-SP" - And I select "CorrId-IdP-B" on the WAYF - And I pass through the IdP - And I give my consent + And I switch to "Tab-A" + And I log in at "CorrId-SP" + And I select "CorrId-IdP-A" on the WAYF + And I switch to "Tab-B" + And I log in at "CorrId-SP" + And I select "CorrId-IdP-B" on the WAYF + And I pass through the IdP + And I give my consent Then the url should match "functional-testing/CorrId-SP/acs" - And I switch to "Tab-A" - And I pass through the IdP - And I give my consent + And I switch to "Tab-A" + And I pass through the IdP + And I give my consent Then the url should match "functional-testing/CorrId-SP/acs" diff --git a/tests/behat.yml b/tests/behat.yml index 3988906fe8..18c453c452 100644 --- a/tests/behat.yml +++ b/tests/behat.yml @@ -44,7 +44,7 @@ default: - OpenConext\EngineBlockFunctionalTestingBundle\Features\Context\TranslationContext: mockTranslator: '@engineblock.functional_testing.mock.translator' - OpenConext\EngineBlockFunctionalTestingBundle\Features\Context\LoggingContext: - logHandler: '@OpenConext\EngineBlockFunctionalTestingBundle\Log\TestLogHandler' + logFile: '/tmp/eb-fixtures/log-records.ndjson' - OpenConext\EngineBlockFunctionalTestingBundle\Features\Context\MinkContext: functional: mink_session: chrome diff --git a/tests/library/EngineBlock/Test/Saml2/AuthnRequestSessionRepositoryTest.php b/tests/library/EngineBlock/Test/Saml2/AuthnRequestSessionRepositoryTest.php index 14c198eddd..6a2272480f 100644 --- a/tests/library/EngineBlock/Test/Saml2/AuthnRequestSessionRepositoryTest.php +++ b/tests/library/EngineBlock/Test/Saml2/AuthnRequestSessionRepositoryTest.php @@ -1,7 +1,7 @@