Add logging when old SAML requests are used

CHANGELOG.md

@@ -29,6 +29,7 @@ Changes:
   * The `0000-00-00 00:00:00` is added for clarity/consistency, as this is probably the default behaviour of your database already.
 * Removed unused index `consent.deleted_at`. Delete this from your production database if it's there.
 * Added a specific error page for unsolicited SAML responses (IdP-initiated SSO without a prior AuthnRequest).
+* Added `max_issue_instant_age` to parameters.yml to configure the logging mechanism. EB will write log entries if it receives requests that are older than this value.
 
 * Stabilized consent checks
   * In order to make the consent hashes more robust, a more consistent way of hashing the user attributes has been introduced

config/packages/parameters.yml.dist

@@ -57,6 +57,9 @@ parameters:
     metadata_add_requested_attributes: all
     ## The number of seconds a Metadata document is deemed valid (default 24h). Must be a positive integer.
     metadata_expiration_time: 86400
+    ## The maximum age (in seconds) of the IssueInstant in incoming SAMLRequests before a warning is logged.
+    ## Default is 24h (86400)
+    max_issue_instant_age: 86400
 
     ##########################################################################################
     ## PHP SETTINGS

config/reference.php

@@ -1466,8 +1466,6 @@
  *     monolog?: MonologConfig,
  *     doctrine?: DoctrineConfig,
  *     doctrine_migrations?: DoctrineMigrationsConfig,
- *     debug?: DebugConfig,
- *     web_profiler?: WebProfilerConfig,
  *     "when@ci"?: array{
  *         imports?: ImportsConfig,
  *         parameters?: ParametersConfig,
@@ -1494,6 +1492,17 @@
  *         debug?: DebugConfig,
  *         web_profiler?: WebProfilerConfig,
  *     },
+ *     "when@prod"?: array{
+ *         imports?: ImportsConfig,
+ *         parameters?: ParametersConfig,
+ *         services?: ServicesConfig,
+ *         framework?: FrameworkConfig,
+ *         security?: SecurityConfig,
+ *         twig?: TwigConfig,
+ *         monolog?: MonologConfig,
+ *         doctrine?: DoctrineConfig,
+ *         doctrine_migrations?: DoctrineMigrationsConfig,
+ *     },
  *     "when@test"?: array{
  *         imports?: ImportsConfig,
  *         parameters?: ParametersConfig,
@@ -1592,6 +1601,7 @@ public static function config(array $config): array
  * @psalm-type RoutesConfig = array{
  *     "when@ci"?: array<string, RouteConfig|ImportConfig|AliasConfig>,
  *     "when@dev"?: array<string, RouteConfig|ImportConfig|AliasConfig>,
+ *     "when@prod"?: array<string, RouteConfig|ImportConfig|AliasConfig>,
  *     "when@test"?: array<string, RouteConfig|ImportConfig|AliasConfig>,
  *     ...<string, RouteConfig|ImportConfig|AliasConfig>
  * }

library/EngineBlock/Application/DiContainer.php

@@ -437,6 +437,11 @@ public function getForbiddenSignatureMethods()
         return (array) $this->container->getParameter('forbidden_signature_methods');
     }
 
+    public function getMaxIssueInstantAge(): int
+    {
+        return (int) $this->container->getParameter('max_issue_instant_age');
+    }
+
     /**
      * @return AllowedSchemeValidator
      */

library/EngineBlock/Corto/Adapter.php

@@ -374,7 +374,8 @@ protected function _configureProxyServer(EngineBlock_Corto_ProxyServer $proxySer
         $proxyServer->setConfigs(array(
             'ConsentStoreValues' => $settings->isConsentStoreValuesActive(),
             'metadataValidUntilSeconds' => 86400, // This sets the time (in seconds) the entity metadata is valid.
-            'forbiddenSignatureMethods' => $settings->getForbiddenSignatureMethods()
+            'forbiddenSignatureMethods' => $settings->getForbiddenSignatureMethods(),
+            'maxIssueInstantAge' => $settings->getMaxIssueInstantAge(),
         ));
 
         $this->configureProxyCertificates($proxyServer);

library/EngineBlock/Corto/Module/Bindings.php

@@ -587,7 +587,7 @@ protected function _verifyKnownIdP($messageIssuer, $destination = '')
     }
 
     /**
-     * Check if the IssueInstant of the message is too far out of sync
+     * Check if the IssueInstant of the message is too far out of sync or too old
      * @param integer $issueInstant
      * @param string $type
      * @param string $entityid
@@ -609,6 +609,20 @@ protected function _checkIssueInstant($issueInstant, $type, $entityid)
                 )
             );
         }
+
+        $maxAge = $this->_server->getConfig('maxIssueInstantAge', 86400);
+        if ($timeDelta > $maxAge) {
+            $this->_logger->warning(
+                sprintf(
+                    'IssueInstant of SAML message from %s "%s" is %d seconds old (threshold: %d seconds); '
+                    . 'request may originate from a bookmarked or replayed URL',
+                    $type,
+                    $entityid,
+                    $timeDelta,
+                    $maxAge
+                )
+            );
+        }
     }
 
     public function send(

tests/library/EngineBlock/Test/Corto/Module/BindingsTest.php

@@ -21,6 +21,7 @@
 use OpenConext\EngineBlock\Metadata\Entity\ServiceProvider;
 use OpenConext\EngineBlockBundle\Bridge\DiContainerRuntime;
 use PHPUnit\Framework\TestCase;
+use Psr\Log\LoggerInterface;
 use SAML2\Assertion;
 use SAML2\Assertion\Validation\ConstraintValidator\NotBefore;
 use SAML2\Assertion\Validation\ConstraintValidator\NotOnOrAfter;
@@ -109,6 +110,72 @@ public function test_saml2_library_error_messages_we_specifically_test_have_not_
         );
     }
 
+    public function test_checkIssueInstant_logs_warning_when_request_exceeds_max_age(): void
+    {
+        $maxAge = 86400;
+        $issueInstant = time() - $maxAge - 1;
+
+        $logger = m::mock(LoggerInterface::class);
+        $logger->shouldReceive('notice')->once(); // clock-drift notice still fires (delta > 30 s)
+        $logger->shouldReceive('warning')->once()->withArgs(function (string $message) use ($maxAge): bool {
+            return str_contains($message, 'bookmarked or replayed URL')
+                && str_contains($message, (string)$maxAge);
+        });
+
+        $proxyServer = Phake::mock('EngineBlock_Corto_ProxyServer');
+        Phake::when($proxyServer)->getConfig('maxIssueInstantAge', 86400)->thenReturn($maxAge);
+
+        $bindings = new EngineBlock_Corto_Module_Bindings($proxyServer);
+        $this->injectLogger($bindings, $logger);
+
+        $method = new ReflectionMethod(EngineBlock_Corto_Module_Bindings::class, '_checkIssueInstant');
+        $method->invoke($bindings, $issueInstant, 'SP', 'https://sp.example.edu');
+    }
+
+    public function test_checkIssueInstant_does_not_warn_when_request_is_within_max_age(): void
+    {
+        $maxAge = 86400;
+        $issueInstant = time() - $maxAge + 5;
+
+        $logger = m::mock(LoggerInterface::class);
+        $logger->shouldReceive('notice')->once(); // clock-drift notice fires (delta > 30 s)
+        $logger->shouldNotReceive('warning');
+
+        $proxyServer = Phake::mock('EngineBlock_Corto_ProxyServer');
+        Phake::when($proxyServer)->getConfig('maxIssueInstantAge', 86400)->thenReturn($maxAge);
+
+        $bindings = new EngineBlock_Corto_Module_Bindings($proxyServer);
+        $this->injectLogger($bindings, $logger);
+
+        $method = new ReflectionMethod(EngineBlock_Corto_Module_Bindings::class, '_checkIssueInstant');
+        $method->invoke($bindings, $issueInstant, 'SP', 'https://sp.example.edu');
+    }
+
+    public function test_checkIssueInstant_does_not_warn_when_request_is_in_the_future(): void
+    {
+        $maxAge = 86400;
+        $issueInstant = time() + 100;
+
+        $logger = m::mock(LoggerInterface::class);
+        $logger->shouldReceive('notice')->once(); // clock-drift notice fires (delta > 30 s)
+        $logger->shouldNotReceive('warning');
+
+        $proxyServer = Phake::mock('EngineBlock_Corto_ProxyServer');
+        Phake::when($proxyServer)->getConfig('maxIssueInstantAge', 86400)->thenReturn($maxAge);
+
+        $bindings = new EngineBlock_Corto_Module_Bindings($proxyServer);
+        $this->injectLogger($bindings, $logger);
+
+        $method = new ReflectionMethod(EngineBlock_Corto_Module_Bindings::class, '_checkIssueInstant');
+        $method->invoke($bindings, $issueInstant, 'SP', 'https://sp.example.edu');
+    }
+
+    private function injectLogger(EngineBlock_Corto_Module_Bindings $bindings, LoggerInterface $logger): void
+    {
+        $property = new ReflectionProperty(EngineBlock_Corto_Module_Bindings::class, '_logger');
+        $property->setValue($bindings, $logger);
+    }
+
     /**
      * Provides a list of paths to response xml files and certificate files
      *