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

@@ -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:

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

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

src/Attribute/RequiresActiveSession.php

@@ -0,0 +1,28 @@
+<?php
+
+/**
+ * Copyright 2024 SURFnet B.V.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+declare(strict_types = 1);
+
+namespace Surfnet\Tiqr\Attribute;
+
+use Attribute;
+
+#[Attribute(Attribute::TARGET_CLASS | Attribute::TARGET_METHOD)]
+class RequiresActiveSession
+{
+}

src/Controller/AuthenticationNotificationController.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\Exception\UserNotExistsException;
 use Surfnet\Tiqr\Tiqr\TiqrServiceInterface;
 use Surfnet\Tiqr\Tiqr\TiqrUserRepositoryInterface;
@@ -52,6 +53,7 @@ public function __construct(
      * @throws InvalidArgumentException
      */
     #[Route(path: '/authentication/notification', name: 'app_identity_authentication_notification', methods: ['POST'])]
+    #[RequiresActiveSession]
     public function __invoke(): Response
     {
         $nameId = $this->authenticationService->getNameId();

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();

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) {

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
     {

src/EventSubscriber/RequiresActiveSessionAttributeListener.php

@@ -0,0 +1,96 @@
+<?php
+
+/**
+ * Copyright 2024 SURFnet B.V.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+declare(strict_types = 1);
+
+namespace Surfnet\Tiqr\EventSubscriber;
+
+use Psr\Log\LoggerInterface;
+use RuntimeException;
+use Surfnet\Tiqr\Attribute\RequiresActiveSession;
+use Surfnet\Tiqr\Service\SessionCorrelationIdService;
+use Surfnet\Tiqr\WithContextLogger;
+use Symfony\Component\EventDispatcher\EventSubscriberInterface;
+use Symfony\Component\HttpFoundation\Exception\SessionNotFoundException;
+use Symfony\Component\HttpKernel\Event\ControllerArgumentsEvent;
+use Symfony\Component\HttpKernel\KernelEvents;
+use Symfony\Component\Security\Core\Exception\AccessDeniedException;
+use function is_array;
+
+/**
+ * This listener acts when the given route has a #[RequiresActiveSession] attribute.
+ * When a route is marked as to have a required active session this listener will deny access when there is none.
+ */
+final readonly class RequiresActiveSessionAttributeListener implements EventSubscriberInterface
+{
+    private string $sessionName;
+
+    /**
+     * @param array<string, string> $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]];
+    }
+}

src/EventSubscriber/SessionStateListener.php

@@ -0,0 +1,90 @@
+<?php
+
+/**
+ * Copyright 2024 SURFnet B.V.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+declare(strict_types = 1);
+
+namespace Surfnet\Tiqr\EventSubscriber;
+
+use Psr\Log\LoggerInterface;
+use RuntimeException;
+use Surfnet\Tiqr\Service\SessionCorrelationIdService;
+use Surfnet\Tiqr\WithContextLogger;
+use Symfony\Component\EventDispatcher\EventSubscriberInterface;
+use Symfony\Component\HttpFoundation\Exception\SessionNotFoundException;
+use Symfony\Component\HttpKernel\Event\RequestEvent;
+use Symfony\Component\HttpKernel\KernelEvents;
+
+/**
+ * Listen to all incoming requests and log the session state information.
+ */
+final readonly class SessionStateListener implements EventSubscriberInterface
+{
+    private string $sessionName;
+
+    /**
+     * @param array<string, string> $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]];
+    }
+}

src/Service/SessionCorrelationIdService.php

@@ -0,0 +1,61 @@
+<?php
+/**
+ * Copyright 2024 SURFnet B.V.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+declare(strict_types = 1);
+
+namespace Surfnet\Tiqr\Service;
+
+use RuntimeException;
+use Symfony\Component\HttpFoundation\RequestStack;
+
+final readonly class SessionCorrelationIdService
+{
+    private string $sessionName;
+    private ?string $correlationIdSalt;
+
+    /**
+     * @param array<string, string> $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);
+    }
+}