Merge pull request #261 from opcodesio/bug/horizon-log-fixes

fix Horizon log processing edge cases

public/mix-manifest.json

@@ -1,5 +1,5 @@
 {
-    "/app.js": "/app.js?id=e7bdf4c9df5545d0907880d43b7adf71",
+    "/app.js": "/app.js?id=c8c3c417b14e0e0f6f9d15caea9a1d4a",
     "/app.css": "/app.css?id=2644d93568c08a41a0612c7c2c38618e",
     "/img/log-viewer-128.png": "/img/log-viewer-128.png?id=d576c6d2e16074d3f064e60fe4f35166",
     "/img/log-viewer-32.png": "/img/log-viewer-32.png?id=f8ec67d10f996aa8baf00df3b61eea6d",

resources/js/components/BaseLogTable.vue

@@ -150,7 +150,8 @@ const clearQuery = () => {
 }
 
 const getDataAtPath = (obj, path) => {
-  return String(path.split('.').reduce((acc, part) => acc && acc[part], obj));
+  const value = path.split('.').reduce((acc, part) => acc && acc[part], obj);
+  return typeof value === 'undefined' ? '' : String(value);
 }
 
 const hasContext = (log) => {

src/Logs/HorizonLog.php

@@ -8,7 +8,7 @@
 class HorizonLog extends Log
 {
     public static string $name = 'Laravel Horizon';
-    public static string $regex = '/\s*(?P<datetime>\d{4}-\d\d-\d\d \d\d:\d\d:\d\d) (?<message>\S+) \.* ?(?<duration>\d+\.?\d*\S+)? (?P<level>\S+)/';
+    public static string $regex = '/^.*(?P<datetime>\d{4}-\d\d-\d\d \d\d:\d\d:\d\d) (?<message>\S+) \.* ?(?<duration>\d[\d\s\.\w]+)? (?P<level>\S+)\R?/m';
     public static string $levelClass = HorizonStatusLevel::class;
     public static array $columns = [
         ['label' => 'Datetime', 'data_path' => 'datetime'],

tests/Unit/HorizonLogs/HorizonNewLogsTest.php

@@ -5,7 +5,7 @@
 use Opcodes\LogViewer\Logs\LogType;
 
 it('can process new Horizon logs', function () {
-    $file = generateLogFile('horizon_new_dummy.log', content: <<<EOF
+    $file = generateLogFile('horizon_new.log', content: <<<EOF
 Horizon started successfully.
   2023-07-22 16:13:33 App\Jobs\TestJob ............................... RUNNING
   2023-07-22 16:13:34 App\Jobs\TestJob ............................... 1s DONE
@@ -29,3 +29,43 @@
         ->and($logs[1]->message)->toBe('App\Jobs\TestJob')
         ->and($logs[1]->context['duration'])->toBe('1s');
 });
+
+it('processes weird cases', function () {
+    $file = generateLogFile('horizon_new_weird.log', content: <<<EOF
+Horizon started successfully.
+  2023-08-17 07:22:32 App\Jobs\TestJob  1 s DONE
+  2023-08-18 06:05:03 App\Jobs\TestJob  32 s. DONE
+  2023-08-19 04:31:07 App\Jobs\TestJob .... 12 sek DONE
+  2023-08-20 02:15:58 App\Jobs\TestJob  2023-08-20 02:15:59 App\Jobs\TestJob  25.14ms DONE
+EOF);
+    $file = new LogFile($file->path);
+
+    expect($file->type()->value)->toBe(LogType::HORIZON); // HorizonLog
+
+    $logReader = $file->logs()->scan();
+
+    expect($logs = $logReader->get())->toHaveCount(4)
+        ->and($logs[0]->datetime->toDateTimeString())->toBe('2023-08-17 07:22:32')
+        ->and($logs[0]->level)->toBe('DONE')
+        ->and($logs[0]->getLevel())->toBeInstanceOf(HorizonStatusLevel::class)
+        ->and($logs[0]->getLevel()->getName())->toBe('Done')
+        ->and($logs[0]->message)->toBe('App\Jobs\TestJob')
+        ->and($logs[0]->context['duration'])->toBe('1 s')
+
+        ->and($logs[1]->datetime->toDateTimeString())->toBe('2023-08-18 06:05:03')
+        ->and($logs[1]->level)->toBe('DONE')
+        ->and($logs[1]->message)->toBe('App\Jobs\TestJob')
+        ->and($logs[1]->context['duration'])->toBe('32 s.')
+
+        ->and($logs[2]->datetime->toDateTimeString())->toBe('2023-08-19 04:31:07')
+        ->and($logs[2]->level)->toBe('DONE')
+        ->and($logs[2]->message)->toBe('App\Jobs\TestJob')
+        ->and($logs[2]->context['duration'])->toBe('12 sek')
+
+        // this one is weird, but let's drop the incomplete beginning and assume the rest of the line is
+        // the correct log entry.
+        ->and($logs[3]->datetime->toDateTimeString())->toBe('2023-08-20 02:15:59')
+        ->and($logs[3]->level)->toBe('DONE')
+        ->and($logs[3]->message)->toBe('App\Jobs\TestJob')
+        ->and($logs[3]->context['duration'])->toBe('25.14ms');
+});