Updated functionality for logging failed access

- Added testing to cover.
- Linked logging into Laravel's monolog logging system and made log
channel configurable.
- Updated env var names to be specific to login access.
- Added extra locations as to where failed logins would be captured.

Related to #1881 and #728

diff --git a/.env.example.complete b/.env.example.complete
index 26dfdc54b2efd15749bef423f104a852e103512f..d7dd02b9a580c9767d7dd63ae96794ed8f4ab3c1 100644 (file)
--- a/.env.example.complete
+++ b/.env.example.complete
@@ -272,8 +272,10 @@ API_MAX_ITEM_COUNT=500
 # The number of API requests that can be made per minute by a single user.
 API_REQUESTS_PER_MIN=180
 
 # The number of API requests that can be made per minute by a single user.
 API_REQUESTS_PER_MIN=180
 

-# Failed access
-# message to log into webserver logs in case of failed access, for further processing by tools like Fail2Ban
-# Apache users should use : user "%u" authentication failure for "BookStack"
-# Nginx  users should use : user "%u" was not found in "BookStack"
-FAILED_ACCESS_MESSAGE=''
+# Enable the logging of failed email+password logins with the given message
+# The defaul log channel below uses the php 'error_log' function which commonly
+# results in messages being output to the webserver error logs.
+# The message can contain a %u parameter which will be replaced with the login
+# user identifier (Username or email).
+LOG_FAILED_LOGIN_MESSAGE=false
+LOG_FAILED_LOGIN_CHANNEL=errorlog_plain_webserver

diff --git a/app/Actions/ActivityService.php b/app/Actions/ActivityService.php
index 0e3ac78611fec3188801e81e75bc6f6231e935de..e6b004f01fb0bc15d3b892ba6f56c49676e31cdc 100644 (file)
--- a/app/Actions/ActivityService.php
+++ b/app/Actions/ActivityService.php
@@ -4,6 +4,7 @@ use BookStack\Auth\Permissions\PermissionService;
 use BookStack\Auth\User;
 use BookStack\Entities\Entity;
 use Illuminate\Support\Collection;
 use BookStack\Auth\User;
 use BookStack\Entities\Entity;
 use Illuminate\Support\Collection;

+use Illuminate\Support\Facades\Log;

 
 class ActivityService
 {
 
 class ActivityService
 {


@@ -49,7 +50,7 @@ class ActivityService
     protected function newActivityForUser(string $key, ?int $bookId = null): Activity
     {
         return $this->activity->newInstance()->forceFill([
     protected function newActivityForUser(string $key, ?int $bookId = null): Activity
     {
         return $this->activity->newInstance()->forceFill([

-            'key' => strtolower($key),
+            'key'     => strtolower($key),

             'user_id' => $this->user->id,
             'book_id' => $bookId ?? 0,
         ]);
             'user_id' => $this->user->id,
             'book_id' => $bookId ?? 0,
         ]);


@@ -64,8 +65,8 @@ class ActivityService
     {
         $activities = $entity->activity()->get();
         $entity->activity()->update([
     {
         $activities = $entity->activity()->get();
         $entity->activity()->update([

-            'extra' => $entity->name,
-            'entity_id' => 0,
+            'extra'       => $entity->name,
+            'entity_id'   => 0,

             'entity_type' => '',
         ]);
         return $activities;
             'entity_type' => '',
         ]);
         return $activities;


@@ -99,7 +100,7 @@ class ActivityService
             $query = $this->activity->newQuery()->where('entity_type', '=', $entity->getMorphClass())
                 ->where('entity_id', '=', $entity->id);
         }
             $query = $this->activity->newQuery()->where('entity_type', '=', $entity->getMorphClass())
                 ->where('entity_id', '=', $entity->id);
         }

-        
+

         $activity = $this->permissionService
             ->filterRestrictedEntityRelations($query, 'activities', 'entity_id', 'entity_type')
             ->orderBy('created_at', 'desc')
         $activity = $this->permissionService
             ->filterRestrictedEntityRelations($query, 'activities', 'entity_id', 'entity_type')
             ->orderBy('created_at', 'desc')


@@ -161,19 +162,18 @@ class ActivityService
     }
 
     /**
     }
 
     /**

-     * Log failed accesses, for further processing by tools like Fail2Ban
-     *
-     * @param username
-     * @return void
-      */
-    public function logFailedAccess($username)
+     * Log out a failed login attempt, Providing the given username
+     * as part of the message if the '%u' string is used.
+     */
+    public function logFailedLogin(string $username)

     {
     {

-        $log_msg = config('logging.failed_access_message');
-
-        if (!is_string($username) || !is_string($log_msg) || strlen($log_msg)<1)
+        $message = config('logging.failed_login.message');
+        if (!$message) {

             return;
             return;

+        }

 
 

-        $log_msg = str_replace("%u", $username, $log_msg);
-        error_log($log_msg, 4);
+        $message = str_replace("%u", $username, $message);
+        $channel = config('logging.failed_login.channel');
+        Log::channel($channel)->warning($message);

     }
 }
     }
 }

diff --git a/app/Config/logging.php b/app/Config/logging.php
index ba77ba81e87ac5d6b1daf8bdecfc4f38a6207117..afd56e48256e492a069e1ea996942c6d73940e2e 100644 (file)
--- a/app/Config/logging.php
+++ b/app/Config/logging.php
@@ -1,5 +1,7 @@
 <?php
 
 <?php
 

+use Monolog\Formatter\LineFormatter;
+use Monolog\Handler\ErrorLogHandler;

 use Monolog\Handler\NullHandler;
 use Monolog\Handler\StreamHandler;
 
 use Monolog\Handler\NullHandler;
 use Monolog\Handler\StreamHandler;
 


@@ -73,6 +75,19 @@ return [
             'level' => 'debug',
         ],
 
             'level' => 'debug',
         ],
 

+        // Custom errorlog implementation that logs out a plain,
+        // non-formatted message intended for the webserver log.
+        'errorlog_plain_webserver' => [
+            'driver' => 'monolog',
+            'level' => 'debug',
+            'handler' => ErrorLogHandler::class,
+            'handler_with' => [4],
+            'formatter' => LineFormatter::class,
+            'formatter_with' => [
+                'format' => "%message%",
+            ],
+        ],
+

         'null' => [
             'driver' => 'monolog',
             'handler' => NullHandler::class,
         'null' => [
             'driver' => 'monolog',
             'handler' => NullHandler::class,


@@ -86,9 +101,12 @@ return [
         ],
     ],
 
         ],
     ],
 

-    // Failed Access Message
-    // Defines the message to log into webserver logs in case of failed access,
-    // for further processing by tools like Fail2Ban.
-    'failed_access_message' => env('FAILED_ACCESS_MESSAGE', ''),
+
+    // Failed Login Message
+    // Allows a configurable message to be logged when a login request fails.
+    'failed_login' => [
+        'message' => env('LOG_FAILED_LOGIN_MESSAGE', null),
+        'channel' => env('LOG_FAILED_LOGIN_CHANNEL', 'errorlog_plain_webserver'),
+    ],

 
 ];
 
 ];

diff --git a/app/Http/Controllers/Auth/LoginController.php b/app/Http/Controllers/Auth/LoginController.php
index f031c12cf9873f468292ccbcce8ba71e6d48bc35..cd7a4db3201524c2de7fb1838cd90946ef14c805 100644 (file)
--- a/app/Http/Controllers/Auth/LoginController.php
+++ b/app/Http/Controllers/Auth/LoginController.php
@@ -99,6 +99,7 @@ class LoginController extends Controller
     public function login(Request $request)
     {
         $this->validateLogin($request);
     public function login(Request $request)
     {
         $this->validateLogin($request);

+        $username = $request->get($this->username());

 
         // If the class is using the ThrottlesLogins trait, we can automatically throttle
         // the login attempts for this application. We'll key this by the username and
 
         // If the class is using the ThrottlesLogins trait, we can automatically throttle
         // the login attempts for this application. We'll key this by the username and


@@ -107,9 +108,7 @@ class LoginController extends Controller
             $this->hasTooManyLoginAttempts($request)) {
             $this->fireLockoutEvent($request);
 
             $this->hasTooManyLoginAttempts($request)) {
             $this->fireLockoutEvent($request);
 

-            // Also log some error message
-            Activity::logFailedAccess($request->get($this->username()));
-
+            Activity::logFailedLogin($username);

             return $this->sendLockoutResponse($request);
         }
 
             return $this->sendLockoutResponse($request);
         }
 


@@ -118,6 +117,7 @@ class LoginController extends Controller
                 return $this->sendLoginResponse($request);
             }
         } catch (LoginAttemptException $exception) {
                 return $this->sendLoginResponse($request);
             }
         } catch (LoginAttemptException $exception) {

+            Activity::logFailedLogin($username);

             return $this->sendLoginAttemptExceptionResponse($exception, $request);
         }
 
             return $this->sendLoginAttemptExceptionResponse($exception, $request);
         }
 


@@ -126,9 +126,7 @@ class LoginController extends Controller
         // user surpasses their maximum number of attempts they will get locked out.
         $this->incrementLoginAttempts($request);
 
         // user surpasses their maximum number of attempts they will get locked out.
         $this->incrementLoginAttempts($request);
 

-        // Also log some error message
-        Activity::logFailedAccess($request->get($this->username()));
-
+        Activity::logFailedLogin($username);

         return $this->sendFailedLoginResponse($request);
     }
 
         return $this->sendFailedLoginResponse($request);
     }
 

diff --git a/phpunit.xml b/phpunit.xml
index 85538c446a2438d7df122dd570b5141c64d1dbec..70f1c1f9c3ed341b39af5baa54e79af2de7a70ab 100644 (file)
--- a/phpunit.xml
+++ b/phpunit.xml
@@ -51,5 +51,7 @@
         <server name="DEBUGBAR_ENABLED" value="false"/>
         <server name="SAML2_ENABLED" value="false"/>
         <server name="API_REQUESTS_PER_MIN" value="180"/>
         <server name="DEBUGBAR_ENABLED" value="false"/>
         <server name="SAML2_ENABLED" value="false"/>
         <server name="API_REQUESTS_PER_MIN" value="180"/>

+        <server name="LOG_FAILED_LOGIN_MESSAGE" value=""/>
+        <server name="LOG_FAILED_LOGIN_CHANNEL" value="testing"/>

     </php>
 </phpunit>
     </php>
 </phpunit>

diff --git a/tests/Auth/AuthTest.php b/tests/Auth/AuthTest.php
index f1f47696641ac4978f2dc33c87a93b5b8805a3e6..8900eeeba10e39c9a75590f716343b3f64124221 100644 (file)
--- a/tests/Auth/AuthTest.php
+++ b/tests/Auth/AuthTest.php
@@ -401,6 +401,18 @@ class AuthTest extends BrowserKitTest
         $this->assertFalse(auth('saml2')->check());
     }
 
         $this->assertFalse(auth('saml2')->check());
     }
 

+    public function test_failed_logins_are_logged_when_message_configured()
+    {
+        $log = $this->withTestLogger();
+        config()->set(['logging.failed_login.message' => 'Failed login for %u']);
+
+        $this->post('/login', ['email' => '[email protected]', 'password' => 'cattreedog']);
+        $this->assertTrue($log->hasWarningThatContains('Failed login for [email protected]'));
+
+        $this->post('/login', ['email' => '[email protected]', 'password' => 'password']);
+        $this->assertFalse($log->hasWarningThatContains('Failed login for [email protected]'));
+    }
+

     /**
      * Perform a login
      */
     /**
      * Perform a login
      */

diff --git a/tests/Auth/LdapTest.php b/tests/Auth/LdapTest.php
index ed8748f08ddff85a32304b61a5680d7b8cc36aa8..0d92241bbe30c59acc93a9c089bcfb2b06a43053 100644 (file)
--- a/tests/Auth/LdapTest.php
+++ b/tests/Auth/LdapTest.php
@@ -593,4 +593,17 @@ class LdapTest extends BrowserKitTest
 
         $this->see('A user with the email [email protected] already exists but with different credentials');
     }
 
         $this->see('A user with the email [email protected] already exists but with different credentials');
     }

+
+    public function test_failed_logins_are_logged_when_message_configured()
+    {
+        $log = $this->withTestLogger();
+        config()->set(['logging.failed_login.message' => 'Failed login for %u']);
+
+        $this->commonLdapMocks(1, 1, 1, 1, 1);
+        $this->mockLdap->shouldReceive('searchAndGetEntries')->times(1)
+            ->andReturn(['count' => 0]);
+
+        $this->post('/login', ['username' => 'timmyjenkins', 'password' => 'cattreedog']);
+        $this->assertTrue($log->hasWarningThatContains('Failed login for timmyjenkins'));
+    }

 }
 }

diff --git a/tests/Unit/ConfigTest.php b/tests/Unit/ConfigTest.php
index 69b737d7df4ac3a88b03b0fcbffa07467d516a6b..1374b3aa9e288b3405c61fe2afe5834d3f40c481 100644 (file)
--- a/tests/Unit/ConfigTest.php
+++ b/tests/Unit/ConfigTest.php
@@ -1,5 +1,6 @@
 <?php namespace Tests\Unit;
 
 <?php namespace Tests\Unit;
 

+use Illuminate\Support\Facades\Log;

 use Tests\TestCase;
 
 /**
 use Tests\TestCase;
 
 /**


@@ -36,6 +37,28 @@ class ConfigTest extends TestCase
         $this->checkEnvConfigResult('APP_URL', $oldDefault, 'app.url', '');
     }
 
         $this->checkEnvConfigResult('APP_URL', $oldDefault, 'app.url', '');
     }
 

+    public function test_errorlog_plain_webserver_channel()
+    {
+        // We can't full test this due to it being targeted for the SAPI logging handler
+        // so we just overwrite that component so we can capture the error log output.
+        config()->set([
+            'logging.channels.errorlog_plain_webserver.handler_with' => [0],
+        ]);
+
+        $temp = tempnam(sys_get_temp_dir(), 'bs-test');
+        $original = ini_set( 'error_log', $temp);
+
+        Log::channel('errorlog_plain_webserver')->info('Aww, look, a cute puppy');
+
+        ini_set( 'error_log', $original);
+
+        $output = file_get_contents($temp);
+        $this->assertStringContainsString('Aww, look, a cute puppy', $output);
+        $this->assertStringNotContainsString('INFO', $output);
+        $this->assertStringNotContainsString('info', $output);
+        $this->assertStringNotContainsString('testing', $output);
+    }
+

     /**
      * Set an environment variable of the given name and value
      * then check the given config key to see if it matches the given result.
     /**
      * Set an environment variable of the given name and value
      * then check the given config key to see if it matches the given result.