From 76473dba531ee272bf41a2070e895984092925ec Mon Sep 17 00:00:00 2001 From: Martijn Harte Date: Thu, 12 Sep 2024 08:59:30 +0200 Subject: [PATCH] Improve logging on session related errors Prior to this change there we weren't able to keep track of sessions that got lost. This change allows us to see every time a session is created and distinguish them by their correlation id. Log an error on a route that requires an active session when there is none Prior to this change all routes were able to called, even though the user might not have had an active session This change will start logging errors when the session wasn't found, or is in an unexpected state Prior to this change session information got lost. We had no way of tracking down what happened to user sessions in the logs. This change logs whether a session existed and if it's in a valid state. Log information is enriched with a correlation id to be able to distinguish them. See https://www.pivotaltracker.com/n/projects/1163646/stories/188205214 --- config/openconext/parameters.yaml.dist | 3 + config/packages/framework.yaml | 4 +- config/services.yaml | 2 + src/Attribute/RequiresActiveSession.php | 28 ++ .../AuthenticationNotificationController.php | 2 + src/Controller/AuthenticationQrController.php | 2 + .../AuthenticationStatusController.php | 3 +- src/Controller/RegistrationController.php | 5 +- ...RequiresActiveSessionAttributeListener.php | 96 +++++++ src/EventSubscriber/SessionStateListener.php | 90 +++++++ src/Service/SessionCorrelationIdService.php | 61 +++++ src/Session/LoggingSessionFactory.php | 70 +++++ src/Tiqr/Legacy/TiqrService.php | 1 - ...iresActiveSessionAttributeListenerTest.php | 245 ++++++++++++++++++ .../SessionStateListenerTest.php | 221 ++++++++++++++++ .../SessionCorrelationIdServiceTest.php | 74 ++++++ .../Session/LoggingSessionFactoryTest.php | 56 ++++ 17 files changed, 958 insertions(+), 5 deletions(-) create mode 100644 src/Attribute/RequiresActiveSession.php create mode 100644 src/EventSubscriber/RequiresActiveSessionAttributeListener.php create mode 100644 src/EventSubscriber/SessionStateListener.php create mode 100644 src/Service/SessionCorrelationIdService.php create mode 100644 src/Session/LoggingSessionFactory.php create mode 100644 tests/Unit/EventSubscriber/RequiresActiveSessionAttributeListenerTest.php create mode 100644 tests/Unit/EventSubscriber/SessionStateListenerTest.php create mode 100644 tests/Unit/Service/SessionCorrelationIdServiceTest.php create mode 100644 tests/Unit/Session/LoggingSessionFactoryTest.php diff --git a/config/openconext/parameters.yaml.dist b/config/openconext/parameters.yaml.dist index 5705b9f8..555177c9 100644 --- a/config/openconext/parameters.yaml.dist +++ b/config/openconext/parameters.yaml.dist @@ -7,6 +7,9 @@ parameters: # A secret key that's used to generate certain security-related tokens app_secret: ThisTokenIsNotSoSecretChangeIt + # A secret salt used to hash the correlationId for logging based on the session_id + correlation_id_salt: 'changeMeToAtLeast16CharsOfRandomString' + # All locales supported by the application default_locale: en_GB locales: diff --git a/config/packages/framework.yaml b/config/packages/framework.yaml index 16aae45d..f04eec90 100644 --- a/config/packages/framework.yaml +++ b/config/packages/framework.yaml @@ -14,8 +14,10 @@ framework: # Remove or comment this section to explicitly disable session support. session: handler_id: null - cookie_secure: auto + cookie_secure: true cookie_samesite: none + name: sess_tiqr + cookie_httponly: true router: strict_requirements: null utf8: true diff --git a/config/services.yaml b/config/services.yaml index d1b7ac86..8e2963ef 100644 --- a/config/services.yaml +++ b/config/services.yaml @@ -19,6 +19,8 @@ services: $locales: '%locales%' $tiqrConfiguration: '%tiqr_library_options%' $appSecret: '%app_secret%' + $sessionOptions: '%session.storage.options%' + $correlationIdSalt: '%correlation_id_salt%' # makes classes in src/ available to be used as services # this creates a service per class whose id is the fully-qualified class name diff --git a/src/Attribute/RequiresActiveSession.php b/src/Attribute/RequiresActiveSession.php new file mode 100644 index 00000000..98d87bfb --- /dev/null +++ b/src/Attribute/RequiresActiveSession.php @@ -0,0 +1,28 @@ +authenticationService->getNameId(); diff --git a/src/Controller/AuthenticationQrController.php b/src/Controller/AuthenticationQrController.php index ed3bd456..b7260e03 100644 --- a/src/Controller/AuthenticationQrController.php +++ b/src/Controller/AuthenticationQrController.php @@ -24,6 +24,7 @@ use Psr\Log\LoggerInterface; use Surfnet\GsspBundle\Service\AuthenticationService; use Surfnet\GsspBundle\Service\StateHandlerInterface; +use Surfnet\Tiqr\Attribute\RequiresActiveSession; use Surfnet\Tiqr\Tiqr\TiqrServiceInterface; use Surfnet\Tiqr\WithContextLogger; use Symfony\Component\HttpFoundation\Response; @@ -44,6 +45,7 @@ public function __construct( * @throws InvalidArgumentException */ #[Route(path: '/authentication/qr', name: 'app_identity_authentication_qr', methods: ['GET'])] + #[RequiresActiveSession] public function __invoke(): Response { $nameId = $this->authenticationService->getNameId(); diff --git a/src/Controller/AuthenticationStatusController.php b/src/Controller/AuthenticationStatusController.php index ce5e71c3..5a130c9c 100644 --- a/src/Controller/AuthenticationStatusController.php +++ b/src/Controller/AuthenticationStatusController.php @@ -25,6 +25,7 @@ use Psr\Log\LoggerInterface; use Surfnet\GsspBundle\Service\AuthenticationService; use Surfnet\GsspBundle\Service\StateHandlerInterface; +use Surfnet\Tiqr\Attribute\RequiresActiveSession; use Surfnet\Tiqr\Tiqr\TiqrServiceInterface; use Surfnet\Tiqr\WithContextLogger; use Symfony\Component\HttpFoundation\JsonResponse; @@ -44,6 +45,7 @@ public function __construct( * @throws InvalidArgumentException */ #[Route(path: '/authentication/status', name: 'app_identity_authentication_status', methods: ['GET'])] + #[RequiresActiveSession] public function __invoke(): JsonResponse { try { @@ -57,7 +59,6 @@ public function __invoke(): JsonResponse return $this->refreshAuthenticationPage(); } - $isAuthenticated = $this->tiqrService->isAuthenticated(); if ($isAuthenticated) { diff --git a/src/Controller/RegistrationController.php b/src/Controller/RegistrationController.php index 5ba1c942..67f0a3ba 100644 --- a/src/Controller/RegistrationController.php +++ b/src/Controller/RegistrationController.php @@ -23,6 +23,7 @@ use Psr\Log\LoggerInterface; use Surfnet\GsspBundle\Service\RegistrationService; use Surfnet\GsspBundle\Service\StateHandlerInterface; +use Surfnet\Tiqr\Attribute\RequiresActiveSession; use Surfnet\Tiqr\Exception\NoActiveAuthenrequestException; use Surfnet\Tiqr\Tiqr\Legacy\TiqrService; use Surfnet\Tiqr\Tiqr\TiqrServiceInterface; @@ -90,9 +91,8 @@ public function registration(Request $request): Response * * * @throws \InvalidArgumentException - * - * Requires session cookie to be set to a valid session. */ + #[RequiresActiveSession] #[Route(path: '/registration/status', name: 'app_identity_registration_status', methods: ['GET'])] public function registrationStatus() : Response { @@ -123,6 +123,7 @@ public function registrationStatus() : Response * * @throws \InvalidArgumentException */ + #[RequiresActiveSession] #[Route(path: '/registration/qr/{enrollmentKey}', name: 'app_identity_registration_qr', methods: ['GET'])] public function registrationQr(Request $request, string $enrollmentKey): Response { diff --git a/src/EventSubscriber/RequiresActiveSessionAttributeListener.php b/src/EventSubscriber/RequiresActiveSessionAttributeListener.php new file mode 100644 index 00000000..4ddbbd78 --- /dev/null +++ b/src/EventSubscriber/RequiresActiveSessionAttributeListener.php @@ -0,0 +1,96 @@ + $sessionOptions + */ + public function __construct( + private LoggerInterface $logger, + private SessionCorrelationIdService $sessionCorrelationIdService, + private array $sessionOptions, + ) { + if (!array_key_exists('name', $this->sessionOptions)) { + throw new RuntimeException( + 'The session name (PHP session cookie identifier) could not be found in the session configuration.' + ); + } + $this->sessionName = $this->sessionOptions['name']; + } + + public function onKernelControllerArguments(ControllerArgumentsEvent $event): void + { + if (!is_array($event->getAttributes()[RequiresActiveSession::class] ?? null)) { + return; + } + + $logger = WithContextLogger::from($this->logger, [ + 'correlationId' => $this->sessionCorrelationIdService->generateCorrelationId() ?? '', + 'route' => $event->getRequest()->getRequestUri(), + ]); + + try { + $sessionId = $event->getRequest()->getSession()->getId(); + $sessionCookieId = $event->getRequest()->cookies->get($this->sessionName); + + if (!$sessionCookieId) { + $logger->error('Route requires active session. Active session wasn\'t found. No session cookie was set.'); + + throw new AccessDeniedException(); + } + + if ($sessionId !== $sessionCookieId) { + $logger->error('Route requires active session. Session does not match session cookie.'); + + throw new AccessDeniedException(); + } + } catch (SessionNotFoundException) { + $logger->error('Route requires active session. Active session wasn\'t found.'); + + throw new AccessDeniedException(); + } + } + + public static function getSubscribedEvents(): array + { + return [KernelEvents::CONTROLLER_ARGUMENTS => ['onKernelControllerArguments', 20]]; + } +} diff --git a/src/EventSubscriber/SessionStateListener.php b/src/EventSubscriber/SessionStateListener.php new file mode 100644 index 00000000..33179505 --- /dev/null +++ b/src/EventSubscriber/SessionStateListener.php @@ -0,0 +1,90 @@ + $sessionOptions + */ + public function __construct( + private LoggerInterface $logger, + private SessionCorrelationIdService $sessionCorrelationIdService, + private array $sessionOptions, + ) { + if (!array_key_exists('name', $this->sessionOptions)) { + throw new RuntimeException( + 'The session name (PHP session cookie identifier) could not be found in the session configuration.' + ); + } + $this->sessionName = $this->sessionOptions['name']; + } + + public function onKernelRequest(RequestEvent $event): void + { + $logger = WithContextLogger::from($this->logger, [ + 'correlationId' => $this->sessionCorrelationIdService->generateCorrelationId() ?? '', + 'route' => $event->getRequest()->getRequestUri(), + ]); + + $sessionCookieId = $event->getRequest()->cookies->get($this->sessionName); + if ($sessionCookieId === null) { + $logger->info('User made a request without a session cookie.'); + return; + } + + $logger->info('User made a request with a session cookie.'); + + try { + $sessionId = $event->getRequest()->getSession()->getId(); + $logger->info('User has a session.'); + + if ($sessionId !== $sessionCookieId) { + $logger->error('The session cookie does not match the session id.'); + return; + } + } catch (SessionNotFoundException) { + $logger->info('Session not found.'); + return; + } + + $logger->info('User session matches the session cookie.'); + } + + public static function getSubscribedEvents(): array + { + return [KernelEvents::REQUEST => ['onKernelRequest', 20]]; + } +} diff --git a/src/Service/SessionCorrelationIdService.php b/src/Service/SessionCorrelationIdService.php new file mode 100644 index 00000000..46f529c2 --- /dev/null +++ b/src/Service/SessionCorrelationIdService.php @@ -0,0 +1,61 @@ + $sessionOptions + */ + public function __construct( + private RequestStack $requestStack, + array $sessionOptions, + ?string $correlationIdSalt = null, + ) { + if (!array_key_exists('name', $sessionOptions)) { + throw new RuntimeException( + 'The session name (PHP session cookie identifier) could not be found in the session configuration.' + ); + } + $this->correlationIdSalt = is_null($correlationIdSalt) || strlen($correlationIdSalt) < 16 ? null : $correlationIdSalt; + $this->sessionName = $sessionOptions['name']; + } + + public function generateCorrelationId(): ?string + { + if ($this->correlationIdSalt === null) { + return null; + } + + $sessionCookie = $this->requestStack->getMainRequest()?->cookies->get($this->sessionName); + + if ($sessionCookie === null) { + return null; + } + + return substr(hash('sha256', $sessionCookie.$this->correlationIdSalt), 0, 8); + } +} diff --git a/src/Session/LoggingSessionFactory.php b/src/Session/LoggingSessionFactory.php new file mode 100644 index 00000000..8491197f --- /dev/null +++ b/src/Session/LoggingSessionFactory.php @@ -0,0 +1,70 @@ +logger = WithContextLogger::from( + $monologLogger, + ['correlationId' => $sessionCorrelationIdService->generateCorrelationId() ?? ''], + ); + + parent::__construct($requestStack, $storageFactory, $usageReporter); + } + + public function createSession(): SessionInterface + { + $this->logger->info('Created new session.'); + + return parent::createSession(); + } +} diff --git a/src/Tiqr/Legacy/TiqrService.php b/src/Tiqr/Legacy/TiqrService.php index 3e77d905..181bbb25 100644 --- a/src/Tiqr/Legacy/TiqrService.php +++ b/src/Tiqr/Legacy/TiqrService.php @@ -38,7 +38,6 @@ use Tiqr_Service; use Tiqr_StateStorage_StateStorageInterface; - /** * Wrapper around the legacy Tiqr service. * diff --git a/tests/Unit/EventSubscriber/RequiresActiveSessionAttributeListenerTest.php b/tests/Unit/EventSubscriber/RequiresActiveSessionAttributeListenerTest.php new file mode 100644 index 00000000..55f5ea5f --- /dev/null +++ b/tests/Unit/EventSubscriber/RequiresActiveSessionAttributeListenerTest.php @@ -0,0 +1,245 @@ + '/route']); + + $requestStack = new RequestStack(); + $requestStack->push($request); + + $stubControllerFactory = fn() => new class extends AbstractController { + }; + + $event = new ControllerArgumentsEvent( + self::$kernel, + $stubControllerFactory, + [], $request, + HttpKernelInterface::MAIN_REQUEST + ); + + $dispatcher = new EventDispatcher(); + + $mockLogger = $this->createMock(LoggerInterface::class); + $mockLogger->expects($this->never())->method('log'); + + $listener = new RequiresActiveSessionAttributeListener( + $mockLogger, + new SessionCorrelationIdService( + $requestStack, + ['name' => 'PHPSESSID'], 'Mr6LpJYtuWRDdVR2_7VgTChFhzQ' + ), + ['name' => 'PHPSESSID'], + ); + + $dispatcher->addListener(KernelEvents::REQUEST, [$listener, 'onKernelControllerArguments']); + $dispatcher->dispatch($event, KernelEvents::REQUEST); + } + + public function testItDeniesAccessWhenThereIsNoActiveSession(): void + { + $this->expectException(AccessDeniedException::class); + $this->expectExceptionMessage('Access Denied.'); + + self::bootKernel(); + + $request = new Request(server: ['REQUEST_URI' => '/route']); + + $requestStack = new RequestStack(); + $requestStack->push($request); + + $stubControllerFactory = fn() => new class extends AbstractController { + }; + + $requestType = HttpKernelInterface::MAIN_REQUEST; + $controllerEvent = new ControllerEvent(self::$kernel, $stubControllerFactory, $request, $requestType); + $controllerEvent->setController($stubControllerFactory, [RequiresActiveSession::class => [null]]); + $event = new ControllerArgumentsEvent(self::$kernel, $controllerEvent, [], $request, $requestType); + + $dispatcher = new EventDispatcher(); + + $mockLogger = $this->createMock(LoggerInterface::class); + $mockLogger->expects($this->once()) + ->method('log') + ->with( + LogLevel::ERROR, + 'Route requires active session. Active session wasn\'t found.', + ['correlationId' => '', 'route' => '/route'] + ); + $listener = new RequiresActiveSessionAttributeListener( + $mockLogger, + new SessionCorrelationIdService($requestStack, ['name' => 'PHPSESSID'], 'Mr6LpJYtuWRDdVR2_7VgTChFhzQ'), + ['name' => 'PHPSESSID'], + ); + + $dispatcher->addListener(KernelEvents::REQUEST, [$listener, 'onKernelControllerArguments']); + $dispatcher->dispatch($event, KernelEvents::REQUEST); + } + + public function testItDeniesAccessWhenThereIsNoSessionCookie(): void + { + $this->expectException(AccessDeniedException::class); + $this->expectExceptionMessage('Access Denied.'); + + self::bootKernel(); + + $session = new Session(new MockArraySessionStorage()); + $session->setId(self::SESSION_ID); + + $request = new Request(server: ['REQUEST_URI' => '/route']); + $request->setSession($session); + + $requestStack = new RequestStack(); + $requestStack->push($request); + + $stubControllerFactory = fn() => new class extends AbstractController { + }; + + $requestType = HttpKernelInterface::MAIN_REQUEST; + $controllerEvent = new ControllerEvent(self::$kernel, $stubControllerFactory, $request, $requestType); + $controllerEvent->setController($stubControllerFactory, [RequiresActiveSession::class => [null]]); + $event = new ControllerArgumentsEvent(self::$kernel, $controllerEvent, [], $request, $requestType); + + $dispatcher = new EventDispatcher(); + + $mockLogger = $this->createMock(LoggerInterface::class); + $mockLogger->expects($this->once()) + ->method('log') + ->with( + LogLevel::ERROR, + 'Route requires active session. Active session wasn\'t found. No session cookie was set.', + ['correlationId' => '', 'route' => '/route'] + ); + + $listener = new RequiresActiveSessionAttributeListener( + $mockLogger, + new SessionCorrelationIdService($requestStack, ['name' => 'PHPSESSID'], 'Mr6LpJYtuWRDdVR2_7VgTChFhzQ'), + ['name' => 'PHPSESSID'], + ); + + $dispatcher->addListener(KernelEvents::REQUEST, [$listener, 'onKernelControllerArguments']); + $dispatcher->dispatch($event, KernelEvents::REQUEST); + } + + public function testItDeniesAccessWhenTheActiveSessionDoesNotMatchTheSessionCookie(): void + { + $this->expectException(AccessDeniedException::class); + $this->expectExceptionMessage('Access Denied.'); + + self::bootKernel(); + + $session = new Session(new MockArraySessionStorage()); + $session->setId('erroneous-session-id'); + + $request = new Request(server: ['REQUEST_URI' => '/route'], cookies: ['PHPSESSID' => self::SESSION_ID]); + $request->setSession($session); + + $requestStack = new RequestStack(); + $requestStack->push($request); + + $stubControllerFactory = fn() => new class extends AbstractController { + }; + + $requestType = HttpKernelInterface::MAIN_REQUEST; + $controllerEvent = new ControllerEvent(self::$kernel, $stubControllerFactory, $request, $requestType); + $controllerEvent->setController($stubControllerFactory, [RequiresActiveSession::class => [null]]); + $event = new ControllerArgumentsEvent(self::$kernel, $controllerEvent, [], $request, $requestType); + + $dispatcher = new EventDispatcher(); + + $mockLogger = $this->createMock(LoggerInterface::class); + $mockLogger->expects($this->once()) + ->method('log') + ->with( + LogLevel::ERROR, + 'Route requires active session. Session does not match session cookie.', + ['correlationId' => 'f02614d0', 'route' => '/route'] + ); + + $listener = new RequiresActiveSessionAttributeListener( + $mockLogger, + new SessionCorrelationIdService($requestStack, ['name' => 'PHPSESSID'], 'Mr6LpJYtuWRDdVR2_7VgTChFhzQ'), + ['name' => 'PHPSESSID'], + ); + + $dispatcher->addListener(KernelEvents::REQUEST, [$listener, 'onKernelControllerArguments']); + $dispatcher->dispatch($event, KernelEvents::REQUEST); + } + + public function testItDoesNotThrowWhenTheActiveSessionMatchesTheSessionCookie(): void + { + self::bootKernel(); + + $session = new Session(new MockArraySessionStorage()); + $session->setId(self::SESSION_ID); + + $request = new Request(server: ['REQUEST_URI' => '/route'], cookies: ['PHPSESSID' => self::SESSION_ID]); + $request->setSession($session); + + $requestStack = new RequestStack(); + $requestStack->push($request); + + $stubControllerFactory = fn() => new class extends AbstractController { + }; + + $requestType = HttpKernelInterface::MAIN_REQUEST; + $controllerEvent = new ControllerEvent(self::$kernel, $stubControllerFactory, $request, $requestType); + $controllerEvent->setController($stubControllerFactory, [RequiresActiveSession::class => [null]]); + $event = new ControllerArgumentsEvent(self::$kernel, $controllerEvent, [], $request, $requestType); + + $dispatcher = new EventDispatcher(); + + $mockLogger = $this->createMock(LoggerInterface::class); + $mockLogger->expects($this->never())->method('log'); + + $listener = new RequiresActiveSessionAttributeListener( + $mockLogger, + new SessionCorrelationIdService($requestStack, ['name' => 'PHPSESSID'], 'Mr6LpJYtuWRDdVR2_7VgTChFhzQ'), + ['name' => 'PHPSESSID'], + ); + + $dispatcher->addListener(KernelEvents::REQUEST, [$listener, 'onKernelControllerArguments']); + $dispatcher->dispatch($event, KernelEvents::REQUEST); + } +} diff --git a/tests/Unit/EventSubscriber/SessionStateListenerTest.php b/tests/Unit/EventSubscriber/SessionStateListenerTest.php new file mode 100644 index 00000000..03e28235 --- /dev/null +++ b/tests/Unit/EventSubscriber/SessionStateListenerTest.php @@ -0,0 +1,221 @@ + '/route']); + + $requestStack = new RequestStack(); + $requestStack->push($request); + + $event = new RequestEvent(self::$kernel, $request, HttpKernelInterface::MAIN_REQUEST); + + $dispatcher = new EventDispatcher(); + + $mockLogger = $this->createMock(LoggerInterface::class); + $mockLogger->expects($this->once()) + ->method('log') + ->with( + LogLevel::INFO, + 'User made a request without a session cookie.', + ['correlationId' => '', 'route' => '/route'] + ); + $listener = new SessionStateListener( + $mockLogger, + new SessionCorrelationIdService($requestStack, ['name' => 'PHPSESSID'], 'Mr6LpJYtuWRDdVR2_7VgTChFhzQ'), + ['name' => 'PHPSESSIONID'], + ); + + $dispatcher->addListener(KernelEvents::REQUEST, [$listener, 'onKernelRequest']); + $dispatcher->dispatch($event, KernelEvents::REQUEST); + } + + public function testItLogsWhenUserHasNoSession(): void + { + self::bootKernel(); + + $request = new Request(server: ['REQUEST_URI' => '/route'], cookies: ['PHPSESSID' => self::SESSION_ID]); + + $requestStack = new RequestStack(); + $requestStack->push($request); + + $event = new RequestEvent(self::$kernel, $request, HttpKernelInterface::MAIN_REQUEST); + + $dispatcher = new EventDispatcher(); + + $mockLogger = $this->createMock(LoggerInterface::class); + + $mockLogger->expects($this->exactly(2)) + ->method('log') + ->willReturnCallback(function ($level, $message, $context) { + static $calledMessages = []; + + if (isset($calledMessages[$message])) { + $this->fail('Log message "' . $message . '" was called more than once.'); + } + $calledMessages[$message] = true; + + switch($message) { + case 'Session not found.': + case 'User made a request with a session cookie.': + $this->assertSame(LogLevel::INFO, $level); + $this->assertSame('f02614d0', $context['correlationId']); + $this->assertSame('/route', $context['route']); + break; + default: + $this->fail('Unexpected log message'); + } + + }) + ; + + $listener = new SessionStateListener( + $mockLogger, + new SessionCorrelationIdService($requestStack, ['name' => 'PHPSESSID'], 'Mr6LpJYtuWRDdVR2_7VgTChFhzQ'), + ['name' => 'PHPSESSID'], + ); + + $dispatcher->addListener(KernelEvents::REQUEST, [$listener, 'onKernelRequest']); + $dispatcher->dispatch($event, KernelEvents::REQUEST); + } + + public function testItLogsAnErrorWhenTheSessionIdDoesNotMatchTheSessionCookie(): void + { + self::bootKernel(); + + $session = new Session(new MockArraySessionStorage()); + $session->setId('erroneous-session-id'); + + $request = new Request(server: ['REQUEST_URI' => '/route'], cookies: ['PHPSESSID' => self::SESSION_ID]); + $request->setSession($session); + + $requestStack = new RequestStack(); + $requestStack->push($request); + + $event = new RequestEvent(self::$kernel, $request, HttpKernelInterface::MAIN_REQUEST); + + $dispatcher = new EventDispatcher(); + + $mockLogger = $this->createMock(LoggerInterface::class); + $mockLogger->expects($this->exactly(3)) + ->method('log') + ->willReturnCallback(function ($level, $message, $context) { + static $calledMessages = []; + + if (isset($calledMessages[$message])) { + $this->fail('Log message "' . $message . '" was called more than once.'); + } + $calledMessages[$message] = true; + + switch($message) { + case 'User made a request with a session cookie.': + case 'User has a session.': + case 'The session cookie does not match the session id.': + $this->assertSame($level === LogLevel::ERROR ? LogLevel::ERROR : LogLevel::INFO, $level); + $this->assertSame('f02614d0', $context['correlationId']); + $this->assertSame('/route', $context['route']); + break; + default: + $this->fail('Unexpected log message'); + } + }); + + $listener = new SessionStateListener( + $mockLogger, + new SessionCorrelationIdService($requestStack, ['name' => 'PHPSESSID'], 'Mr6LpJYtuWRDdVR2_7VgTChFhzQ'), + ['name' => 'PHPSESSID'], + ); + + $dispatcher->addListener(KernelEvents::REQUEST, [$listener, 'onKernelRequest']); + $dispatcher->dispatch($event, KernelEvents::REQUEST); + } + + public function testTheUserSessionMatchesTheSessionCookie(): void + { + self::bootKernel(); + + $session = new Session(new MockArraySessionStorage()); + $session->setId(self::SESSION_ID); + + $request = new Request(server: ['REQUEST_URI' => '/route'], cookies: ['PHPSESSID' => self::SESSION_ID]); + $request->setSession($session); + + $requestStack = new RequestStack(); + $requestStack->push($request); + + + $event = new RequestEvent(self::$kernel, $request, HttpKernelInterface::MAIN_REQUEST); + + $dispatcher = new EventDispatcher(); + + $mockLogger = $this->createMock(LoggerInterface::class); + $mockLogger->expects($this->exactly(3)) + ->method('log') + ->willReturnCallback(function ($level, $message, $context) { + static $calledMessages = []; + + if (isset($calledMessages[$message])) { + $this->fail('Log message "' . $message . '" was called more than once.'); + } + $calledMessages[$message] = true; + + switch($message) { + case 'User made a request with a session cookie.': + case 'User has a session.': + case 'User session matches the session cookie.': + $this->assertSame(LogLevel::INFO, $level); + $this->assertSame('f02614d0', $context['correlationId']); + $this->assertSame('/route', $context['route']); + break; + default: + $this->fail('Unexpected log message'); + } + }); + + $listener = new SessionStateListener( + $mockLogger, + new SessionCorrelationIdService($requestStack, ['name' => 'PHPSESSID'], 'Mr6LpJYtuWRDdVR2_7VgTChFhzQ'), + ['name' => 'PHPSESSID'], + ); + + $dispatcher->addListener(KernelEvents::REQUEST, [$listener, 'onKernelRequest']); + $dispatcher->dispatch($event, KernelEvents::REQUEST); + } +} diff --git a/tests/Unit/Service/SessionCorrelationIdServiceTest.php b/tests/Unit/Service/SessionCorrelationIdServiceTest.php new file mode 100644 index 00000000..c457f183 --- /dev/null +++ b/tests/Unit/Service/SessionCorrelationIdServiceTest.php @@ -0,0 +1,74 @@ +push($request); + + $service = new SessionCorrelationIdService($requestStack, ['name' => 'PHPSESSID'], 'Mr6LpJYtuWRDdVR2_7VgTChFhzQ'); + + $this->assertNull($service->generateCorrelationId()); + } + + public function testItGeneratesACorrelationIdBasedOnTheSessionCookie(): void + { + $request = new Request(cookies: ['PHPSESSID' => 'session-id']); + $requestStack = new RequestStack(); + $requestStack->push($request); + + $service = new SessionCorrelationIdService($requestStack, ['name' => 'PHPSESSID'], 'Mr6LpJYtuWRDdVR2_7VgTChFhzQ' + ); + + $this->assertSame('f02614d0', $service->generateCorrelationId()); + } + + + /** + * @dataProvider saltProvider + */ + public function testItWillNotGenerateACorrelationIdWithoutAdequateSalt(?string $salt): void + { + $request = new Request(cookies: ['PHPSESSID' => 'session-id']); + $requestStack = new RequestStack(); + $requestStack->push($request); + + $service = new SessionCorrelationIdService($requestStack, ['name' => 'PHPSESSID'], $salt); + + $this->assertNull($service->generateCorrelationId()); + } + + public function saltProvider(): array + { + return [ + 'empty salt' => [''], + 'null salt' => [null], + 'short salt' => ['abc'], + 'almost_long_enough salt' => ['1234567890ABCDE'], + ]; + } +} diff --git a/tests/Unit/Session/LoggingSessionFactoryTest.php b/tests/Unit/Session/LoggingSessionFactoryTest.php new file mode 100644 index 00000000..dde3e5d5 --- /dev/null +++ b/tests/Unit/Session/LoggingSessionFactoryTest.php @@ -0,0 +1,56 @@ + 'session-id']); + $requestStack = new RequestStack(); + $requestStack->push($request); + + $mockLogger = $this->createMock(LoggerInterface::class); + $mockLogger->expects($this->once()) + ->method('log') + ->with( + LogLevel::INFO, + 'Created new session.', + ['correlationId' => 'f02614d0'] + ); + + $sessionFactory = new LoggingSessionFactory( + $requestStack, + $this->createStub(SessionStorageFactoryInterface::class), + $mockLogger, + new SessionCorrelationIdService($requestStack, ['name' => 'PHPSESSID'], 'Mr6LpJYtuWRDdVR2_7VgTChFhzQ'), + ); + + $this->assertInstanceOf(SessionInterface::class, $sessionFactory->createSession()); + } +}