improved LDAP logging (#5517)

src/Ldap/LdapDriver.php

@@ -21,7 +21,10 @@ class LdapDriver
 {
     private ?Ldap $driver = null;
 
-    public function __construct(private LdapConfiguration $config, private ?LoggerInterface $logger = null)
+    public function __construct(
+        private readonly LdapConfiguration $config,
+        private readonly LoggerInterface $logger
+    )
     {
     }
 
@@ -41,10 +44,8 @@ class LdapDriver
     }
 
     /**
-     * @param string $baseDn
-     * @param string $filter
-     * @param array $attributes
-     * @return array
+     * @param array<int, string> $attributes
+     * @return array{'count': int, array<string, string|array<int, string>>}
      * @throws LdapDriverException
      */
     public function search(string $baseDn, string $filter, array $attributes = []): array
@@ -53,7 +54,7 @@ class LdapDriver
 
         $attributes = array_unique(array_merge($attributes, ['+', '*']));
 
-        $this->logDebug('{action}({base_dn}, {filter}, {attributes})', [
+        $this->logger->debug('{action}({base_dn}, {filter}, {attributes})', [
             'action' => 'ldap_search',
             'base_dn' => $baseDn,
             'filter' => $filter,
@@ -67,7 +68,7 @@ class LdapDriver
             // searchEntries don't return 'count' key as specified by php native function ldap_get_entries()
             $entries['count'] = \count($entries);
         } catch (LdapException $exception) {
-            $this->ldapExceptionHandler($exception);
+            $this->logger->error(\sprintf('Failed to search LDAP: %s', $exception->getMessage()), ['exception' => $exception]);
 
             throw new LdapDriverException('An error occurred with the search operation.');
         }
@@ -80,7 +81,7 @@ class LdapDriver
         $driver = $this->getDriver();
 
         try {
-            $this->logDebug('{action}({bindDn}, ****)', [
+            $this->logger->debug('{action}({bindDn}, ****)', [
                 'action' => 'ldap_bind',
                 'bindDn' => $bindDn,
             ]);
@@ -88,36 +89,9 @@ class LdapDriver
 
             return $bind instanceof Ldap;
         } catch (LdapException $exception) {
-            $this->ldapExceptionHandler($exception, $password);
+            $this->logger->error(\sprintf('Failed binding to LDAP at %s: %s', $bindDn, $exception->getMessage()), ['exception' => new SanitizingException($exception, $password)]);
         }
 
         return false;
     }
-
-    private function ldapExceptionHandler(LdapException $exception, string $password = null): void
-    {
-        $sanitizedException = null !== $password ? new SanitizingException($exception, $password) : $exception;
-
-        switch ($exception->getCode()) {
-            // Error level codes
-            case LdapException::LDAP_SERVER_DOWN:
-                if ($this->logger) {
-                    $this->logger->error('{exception}', ['exception' => $sanitizedException]);
-                }
-                break;
-
-                // Other level codes
-            default:
-                $this->logDebug('{exception}', ['exception' => $sanitizedException]);
-                break;
-        }
-    }
-
-    private function logDebug(string $message, array $context = []): void
-    {
-        if (null === $this->logger) {
-            return;
-        }
-        $this->logger->debug($message, $context);
-    }
 }

tests/Ldap/LdapDriverTest.php

@@ -12,10 +12,13 @@ namespace App\Tests\Ldap;
 use App\Configuration\LdapConfiguration;
 use App\Entity\User;
 use App\Ldap\LdapDriver;
+use App\Ldap\LdapDriverException;
 use App\Tests\Mocks\SystemConfigurationFactory;
+use App\Tests\Mocks\TestLogger;
 use Laminas\Ldap\Exception\LdapException;
 use Laminas\Ldap\Ldap;
 use PHPUnit\Framework\TestCase;
+use Psr\Log\LogLevel;
 
 /**
  * @covers \App\Ldap\LdapDriver
@@ -25,7 +28,7 @@ class LdapDriverTest extends TestCase
     protected function setUp(): void
     {
         parent::setUp();
-        if (!class_exists('Laminas\Ldap\Ldap')) {
+        if (!class_exists(Ldap::class)) {
             $this->markTestSkipped('LDAP is not installed');
         }
     }
@@ -63,6 +66,11 @@ class LdapDriverTest extends TestCase
         $sut = $this->getTestLdapDriver($zendLdap);
         $result = $sut->bind($user->getUserIdentifier(), 'test123');
         self::assertFalse($result);
+
+        $logs = $sut->getLogger()->cleanLogs();
+        self::assertCount(2, $logs);
+        self::assertEquals(LogLevel::ERROR, $logs[1][0]);
+        self::assertStringStartsWith('Failed binding to LDAP at', $logs[1][1]);
     }
 
     public function testSearchSuccess(): void
@@ -75,15 +83,36 @@ class LdapDriverTest extends TestCase
         $result = $sut->search('', '', []);
         self::assertEquals(['count' => 3, 1, 2, 3], $result);
     }
+
+    public function testSearchFailure(): void
+    {
+        $this->expectException(LdapDriverException::class);
+        $zendLdap = $this->getMockBuilder(Ldap::class)->disableOriginalConstructor()->onlyMethods(['bind', 'searchEntries'])->getMock();
+        $zendLdap->expects($this->once())->method('bind');
+        $zendLdap->expects($this->once())->method('searchEntries')->willThrowException(new LdapException());
+
+        $sut = $this->getTestLdapDriver($zendLdap);
+        $result = $sut->search('', '', []);
+        self::assertEquals(['count' => 3, 1, 2, 3], $result);
+
+        $logs = $sut->getLogger()->cleanLogs();
+        self::assertCount(2, $logs);
+        self::assertEquals(LogLevel::DEBUG, $logs[0][0]);
+        self::assertStringStartsWith('Failed to search LDAP', $logs[1][1]);
+        self::assertEquals(LogLevel::ERROR, $logs[1][0]);
+        self::assertStringStartsWith('An error occurred with the search operation', $logs[1][1]);
+    }
 }
 
 class TestLdapDriver extends LdapDriver
 {
     private Ldap $testDriver;
+    public TestLogger $logger;
 
     public function __construct(LdapConfiguration $config, Ldap $ldap)
     {
-        parent::__construct($config);
+        $this->logger = new TestLogger();
+        parent::__construct($config, $this->logger);
         $this->testDriver = $ldap;
     }
 
@@ -91,4 +120,9 @@ class TestLdapDriver extends LdapDriver
     {
         return $this->testDriver;
     }
+
+    public function getLogger(): TestLogger
+    {
+        return $this->logger;
+    }
 }

tests/Mocks/TestLogger.php

@@ -0,0 +1,30 @@
+<?php
+
+/*
+ * This file is part of the Kimai time-tracking app.
+ *
+ * For the full copyright and license information, please view the LICENSE
+ * file that was distributed with this source code.
+ */
+
+namespace App\Tests\Mocks;
+
+use Psr\Log\AbstractLogger;
+
+class TestLogger extends AbstractLogger
+{
+    private array $logs = [];
+
+    public function log($level, string|\Stringable $message, array $context = []): void
+    {
+        $this->logs[] = [$level, $message, $context];
+    }
+
+    public function cleanLogs(): array
+    {
+        $logs = $this->logs;
+        $this->logs = [];
+
+        return $logs;
+    }
+}