Merge pull request #415 from opcodesio/bug/nginx-error-log-multiline-message

fix nginx error logs having multiline messages

Author: arukompas

src/Logs/HttpNginxErrorLog.php

@@ -10,7 +10,7 @@
 class HttpNginxErrorLog extends Log
 {
     public static string $name = 'HTTP Errors (Nginx)';
-    public static string $regex = '/^(?P<datetime>[\d+\/ :]+) \[(?P<level>.+)\] .*?: (?P<errormessage>.+?)(?:, client: (?P<client>.+?))?(?:, server: (?P<server>.+?))?(?:, request: "?(?P<request>.+?)"?)?(?:, host: "?(?P<host>.+?)"?)?$/';
+    public static string $regex = '~^(?P<datetime>[\d+\/ :]+) \[(?P<level>.+?)\] .*?: (?P<errormessage>(?:(?!, client: |, server: |, request: |, upstream: |, host: |, referrer: ).)*(?:\n(?![\d/]|\Z).*)*?)(?:, client: (?P<client>.+?))?(?:, server: (?P<server>.+?))?(?:, request: "?(?P<request>.+?)"?)?(?:, upstream: "?(?P<upstream>.+?)"?)?(?:, host: "?(?P<host>.+?)"?)?(?:, referrer: "?(?P<referrer>.+?)"?)?$~ms';
     public static string $levelClass = NginxStatusLevel::class;
 
     protected function fillMatches(array $matches = []): void
@@ -26,6 +26,8 @@ protected function fillMatches(array $matches = []): void
             'server' => $matches['server'] ?? null,
             'request' => $matches['request'] ?? null,
             'host' => $matches['host'] ?? null,
+            'upstream' => $matches['upstream'] ?? null,
+            'referrer' => $matches['referrer'] ?? null,
         ];
     }
 

tests/Feature/Authorization/CanDownloadFoldersTest.php

@@ -21,8 +21,8 @@ function assertCanDownloadFolder(string $folderName, string $expectedFileName):
 
 function assertCannotDownloadFolder(string $folderName): void
 {
-    get(route('log-viewer.folders.request-download', $folderName))
-        ->assertForbidden();
+get(route('log-viewer.folders.request-download', $folderName))
+->assertForbidden();
 }
 
 test('can download every folder by default', function () {
@@ -33,9 +33,9 @@ function assertCannotDownloadFolder(string $folderName): void
 });
 
 test('cannot download a folder that\'s not found', function () {
-    get(route('log-viewer.folders.request-download', 'notfound'))
-        ->assertNotFound();
-});
+get(route('log-viewer.folders.request-download', 'notfound'))
+->assertNotFound();
+    });
 
 test('"downloadLogFolder" gate can prevent folder download', function () {
     generateLogFiles([$fileName = 'laravel.log']);

tests/Feature/Authorization/CanDownloadLogFileTest.php

@@ -20,8 +20,8 @@ function assertCanDownloadFile(string $fileName): void
 
 function assertCannotDownloadFile(string $fileName): void
 {
-    get(route('log-viewer.files.request-download', $fileName))
-        ->assertForbidden();
+get(route('log-viewer.files.request-download', $fileName))
+->assertForbidden();
 }
 
 test('can download every file by default', function () {
@@ -31,9 +31,9 @@ function assertCannotDownloadFile(string $fileName): void
 });
 
 test('cannot download a file that\'s not found', function () {
-    get(route('log-viewer.files.request-download', 'notfound.log'))
-        ->assertNotFound();
-});
+get(route('log-viewer.files.request-download', 'notfound.log'))
+->assertNotFound();
+    });
 
 test('"downloadLogFile" gate can prevent file download', function () {
     generateLogFiles([$fileName = 'laravel.log']);

tests/Feature/Authorization/CanViewLogViewerTest.php

@@ -6,7 +6,7 @@
 use function Pest\Laravel\get;
 
 test('can define an "auth" callback for authorization', function () {
-    get(route('log-viewer.index'))->assertOk();
+get(route('log-viewer.index'))->assertOk();
 
     // with the gate defined and a false value, it should not be possible to access the log viewer
     LogViewer::auth(fn ($request) => false);
@@ -15,7 +15,7 @@
     // now let's give them access
     LogViewer::auth(fn ($request) => true);
     get(route('log-viewer.index'))->assertOk();
-});
+    });
 
 test('the "auth" callback is given with a Request object to check against', function () {
     LogViewer::auth(function ($request) {
@@ -28,14 +28,14 @@
 });
 
 test('can define a "viewLogViewer" gate as an alternative', function () {
-    get(route('log-viewer.index'))->assertOk();
+get(route('log-viewer.index'))->assertOk();
 
     Gate::define('viewLogViewer', fn ($user = null) => false);
     get(route('log-viewer.index'))->assertForbidden();
 
     Gate::define('viewLogViewer', fn ($user = null) => true);
     get(route('log-viewer.index'))->assertOk();
-});
+    });
 
 test('local environment can use Log Viewer by default', function () {
     app()->detectEnvironment(fn () => 'local');

tests/Unit/AccessLogs/Fixtures/multiline_nginx_error_dummy.log

@@ -0,0 +1,6 @@
+2024/08/21 09:08:18 [error] 2761052#2761052: *84719 upstream sent too big header while reading response header from upstream, client: 123.123.123.123, server: xxx, request: "GET /api/xx/yy/zz?lang=de HTTP/2.0", upstream: "fastcgi://unix:/var/run/php/php8.1-fpm.sock:", host: "xxx", referrer: "http://some-ip:3000/"
+2024/08/21 09:08:19 [error] 2761052#2761052: *84719 FastCGI sent in stderr: "PHP message: [2024-08-21 11:08:18] develop.DEBUG: ActivityService: some message
+PHP message: [2024-08-21 11:08:18] develop.DEBUG: ActivityService: another message
+PHP message: [2024-08-21 11:08:18] develop.DEBUG: ActivityService: blabla:  [{"id":308363,"lat":"xx","lng":"yy"}]
+PHP message: [2024-08-21 11:08:18] develop.INFO: provider Payload:  {"attr1":"t","attr2":14400,"sources":[{"id":"source","lat":xx,"lng":yy,"tm":{"t":{"maxT":2},"c":{"":""}}}],"t":[{"id":308363,"lat":"xx","lng":"yy"}],"g_s_client":false,"reversed":false,"polygon":{"id":4326},"pathSerializer":"g"}
+PHP message: [2024-08-21 11:08:18] develop.DEBUG: Sending request to final Url (V1) https://someurl/path/v1/endpoint?param=***

tests/Unit/AccessLogs/HttpNginxErrorLogTest.php

@@ -43,3 +43,45 @@
         ->and($log->context['request'])->toBe(null)
         ->and($log->context['host'])->toBe(null);
 });
+
+it('can parse multiline nginx log entries', function () {
+    $file = new \Opcodes\LogViewer\LogFile(__DIR__.'/Fixtures/multiline_nginx_error_dummy.log');
+    $file->logs()->scan();
+
+    $logs = $file->logs()->get();
+
+    expect($logs)->toHaveCount(2);
+
+    /** @var HttpNginxErrorLog $firstLog */
+    $firstLog = $logs[0];
+
+    // 2024/08/21 09:08:18 [error] 2761052#2761052: *84719 upstream sent too big header while reading response header from upstream,
+    // client: 123.123.123.123, server: xxx, request: "GET /api/xx/yy/zz?lang=de HTTP/2.0",
+    // upstream: "fastcgi://unix:/var/run/php/php8.1-fpm.sock:", host: "xxx", referrer: "http://some-ip:3000/"
+    expect($firstLog->index)->toBe(0)
+        ->and($firstLog)->toBeInstanceOf(HttpNginxErrorLog::class)
+        ->and($firstLog->datetime->toDateTimeString())->toBe('2024-08-21 09:08:18')
+        ->and($firstLog->level)->toBe('error')
+        ->and($firstLog->message)->toBe('*84719 upstream sent too big header while reading response header from upstream')
+        ->and($firstLog->context['client'])->toBe('123.123.123.123')
+        ->and($firstLog->context['server'])->toBe('xxx')
+        ->and($firstLog->context['request'])->toBe('GET /api/xx/yy/zz?lang=de HTTP/2.0')
+        ->and($firstLog->context['upstream'])->toBe('fastcgi://unix:/var/run/php/php8.1-fpm.sock:')
+        ->and($firstLog->context['host'])->toBe('xxx')
+        ->and($firstLog->context['referrer'])->toBe('http://some-ip:3000/');
+
+    $secondLog = $logs[1];
+
+    expect($secondLog->index)->toBe(1)
+        ->and($secondLog)->toBeInstanceOf(HttpNginxErrorLog::class)
+        ->and($secondLog->datetime->toDateTimeString())->toBe('2024-08-21 09:08:19')
+        ->and($secondLog->level)->toBe('error')
+        ->and($secondLog->message)->toBe(<<<'EOF'
+*84719 FastCGI sent in stderr: "PHP message: [2024-08-21 11:08:18] develop.DEBUG: ActivityService: some message
+PHP message: [2024-08-21 11:08:18] develop.DEBUG: ActivityService: another message
+PHP message: [2024-08-21 11:08:18] develop.DEBUG: ActivityService: blabla:  [{"id":308363,"lat":"xx","lng":"yy"}]
+PHP message: [2024-08-21 11:08:18] develop.INFO: provider Payload:  {"attr1":"t","attr2":14400,"sources":[{"id":"source","lat":xx,"lng":yy,"tm":{"t":{"maxT":2},"c":{"":""}}}],"t":[{"id":308363,"lat":"xx","lng":"yy"}],"g_s_client":false,"reversed":false,"polygon":{"id":4326},"pathSerializer":"g"}
+PHP message: [2024-08-21 11:08:18] develop.DEBUG: Sending request to final Url (V1) https://someurl/path/v1/endpoint?param=***
+EOF);
+
+});