Skip to content

Commit eeb391b

Browse files
arukompasarukompas
authored
Merge pull request #348 from opcodesio/bug/keys-lost-inside-log-resource
preserve keys in LogResource so that context is intact
2 parents 65d945f + 809d76c commit eeb391b

File tree

3 files changed

+185
-170
lines changed

3 files changed

+185
-170
lines changed

‎src/Http/Resources/LogResource.php‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,8 @@
99
*/
1010
class LogResource extends JsonResource
1111
{
12+
public bool $preserveKeys = true;
13+
1214
public function toArray($request): array
1315
{
1416
$level = $this->getLevel();

‎tests/Unit/LaravelLogs/LaravelLogsTest.php‎

Lines changed: 183 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,191 @@
11
<?php
22

3+
use Opcodes\LogViewer\LogLevels\LaravelLogLevel;
34
use Opcodes\LogViewer\Logs\LaravelLog;
45
use Opcodes\LogViewer\Utils\Utils;
56

7+
use function PHPUnit\Framework\assertEquals;
8+
9+
it('can understand the default Laravel log format', function () {
10+
$text = '[2022-08-25 11:16:17] local.DEBUG: Example log entry for the level debug';
11+
12+
$log = new LaravelLog($text, $fileIdentifier = 'laravel.log', $filePosition = 5200, $index = 10);
13+
14+
assertEquals($index, $log->index);
15+
assertEquals(LaravelLogLevel::Debug, $log->level);
16+
assertEquals('local', $log->extra['environment']);
17+
assertEquals('2022-08-25 11:16:17', $log->datetime->toDateTimeString());
18+
assertEquals('Example log entry for the level debug', $log->message);
19+
assertEquals('Example log entry for the level debug', $log->getOriginalText());
20+
assertEquals($fileIdentifier, $log->fileIdentifier);
21+
assertEquals($filePosition, $log->filePosition);
22+
});
23+
24+
it('can understand multi-line logs', function () {
25+
$logText = <<<'EOF'
26+
Example log entry for the level debug
27+
with multiple lines of content.
28+
can contain dumped objects or JSON as well - it's all part of the contents.
29+
EOF;
30+
$text = '[2022-08-25 11:16:17] local.DEBUG: '.$logText;
31+
32+
$log = new LaravelLog($text, 'laravel.log', 0, 0);
33+
34+
assertEquals('Example log entry for the level debug', $log->message);
35+
assertEquals($logText, $log->getOriginalText());
36+
});
37+
38+
it('extracts JSON from the log text', function () {
39+
config(['log-viewer.strip_extracted_context' => true]);
40+
$logText = <<<'EOF'
41+
Example log entry for the level debug
42+
with multiple lines of content.
43+
{"one":1,"two":"two","three":[1,2,3]}
44+
can contain dumped objects or JSON as well - it's all part of the contents.
45+
EOF;
46+
$jsonString = '{"one":1,"two":"two","three":[1,2,3]}';
47+
$text = '[2022-08-25 11:16:17] local.DEBUG: '.$logText;
48+
49+
$log = new LaravelLog($text, 'laravel.log', 0, 0);
50+
51+
assertEquals('Example log entry for the level debug', $log->message);
52+
assertEquals(rtrim(str_replace($jsonString, '', $logText)), $log->getOriginalText());
53+
assertEquals(json_decode($jsonString, true), $log->context);
54+
});
55+
56+
it('extracts JSON, but does not remove from the log text if the config is set to false', function () {
57+
config(['log-viewer.strip_extracted_context' => false]);
58+
$logText = <<<'EOF'
59+
Example log entry for the level debug
60+
with multiple lines of content.
61+
{"one":1,"two":"two","three":[1,2,3]}
62+
can contain dumped objects or JSON as well - it's all part of the contents.
63+
EOF;
64+
$text = '[2022-08-25 11:16:17] local.DEBUG: '.$logText;
65+
66+
$log = new LaravelLog($text, 'laravel.log');
67+
68+
assertEquals('Example log entry for the level debug', $log->message);
69+
assertEquals($logText, $log->getOriginalText());
70+
assertEquals(json_decode('{"one":1,"two":"two","three":[1,2,3]}', true), $log->context);
71+
});
72+
73+
it('extracts JSON from a complex log', function () {
74+
config(['log-viewer.strip_extracted_context' => true]);
75+
$logText = <<<'EOF'
76+
Initiating facebook login.
77+
[HTTP request]
78+
*User ID:* guest
79+
*Request:* GET https://system.test/book/arunas/submit-facebook
80+
*Agent:* Mozilla/5.0 (iPhone; CPU iPhone OS 15_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/19G82 [FBAN/FBIOS;FBDV/iPhone9,3;FBMD/iPhone;FBSN/iOS;FBSV/15.6.1;FBSS/2;FBID/phone;FBLC/da_DK;FBOP/5]
81+
{"permalink":"arunas","session":{"_token":"BpqyiNyinnLamzer4jqzrh9NTyC6emFR41FitMpv","_previous":{"url":"https://system.test/book/arunas/center"},"_flash":{"old":[],"new":[]},"latest_permalink":"arunas"},"ip":"127.0.0.1","user_agent":"Mozilla/5.0 (iPhone; CPU iPhone OS 15_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/19G82 [FBAN/FBIOS;FBDV/iPhone9,3;FBMD/iPhone;FBSN/iOS;FBSV/15.6.1;FBSS/2;FBID/phone;FBLC/da_DK;FBOP/5]"}
82+
EOF;
83+
84+
$jsonString = '{"permalink":"arunas","session":{"_token":"BpqyiNyinnLamzer4jqzrh9NTyC6emFR41FitMpv","_previous":{"url":"https://system.test/book/arunas/center"},"_flash":{"old":[],"new":[]},"latest_permalink":"arunas"},"ip":"127.0.0.1","user_agent":"Mozilla/5.0 (iPhone; CPU iPhone OS 15_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/19G82 [FBAN/FBIOS;FBDV/iPhone9,3;FBMD/iPhone;FBSN/iOS;FBSV/15.6.1;FBSS/2;FBID/phone;FBLC/da_DK;FBOP/5]"}';
85+
$text = '[2022-08-25 11:16:17] local.DEBUG: '.$logText;
86+
87+
$log = new LaravelLog($text, 'laravel.log');
88+
89+
assertEquals('arunas', $log->context['permalink'] ?? null);
90+
assertEquals('Initiating facebook login.', $log->message);
91+
assertEquals(rtrim(str_replace($jsonString, '', $logText)), $log->getOriginalText());
92+
assertEquals(json_decode($jsonString, true), $log->context);
93+
});
94+
95+
it('can understand the optional microseconds in the timestamp', function () {
96+
$text = '[2022-08-25 11:16:17.125000] local.DEBUG: Example log entry for the level debug';
97+
98+
$log = new LaravelLog($text, 'laravel.log', 0, 0);
99+
100+
assertEquals(125000, $log->datetime->micro);
101+
});
102+
103+
it('can understand the optional time offset in the timestamp', function () {
104+
$text = '[2022-08-25 11:16:17.125000+02:00] local.DEBUG: Example log entry for the level debug';
105+
$expectedTimestamp = 1661418977;
106+
107+
$log = new LaravelLog($text, 'laravel.log', 0, 0);
108+
109+
assertEquals($expectedTimestamp, $log->datetime->timestamp);
110+
111+
// Meanwhile, if we switch the time offset an hour forward,
112+
// we can expect the timestamp to be reduced by 3600 seconds.
113+
$text = '[2022-08-25 11:16:17.125000+03:00] local.DEBUG: Example log entry for the level debug';
114+
$newExpectedTimestamp = $expectedTimestamp - 3600;
115+
116+
$log = new LaravelLog($text, 'laravel.log', 0, 0);
117+
118+
assertEquals($newExpectedTimestamp, $log->datetime->timestamp);
119+
});
120+
121+
it('can handle text in-between timestamp and environment/severity', function () {
122+
$text = '[2022-08-25 11:16:17] some additional text [!@#$%^&] and characters // !@#$ local.DEBUG: Example log entry for the level debug';
123+
$expectedAdditionalText = 'some additional text [!@#$%^&] and characters // !@#$';
124+
125+
$log = new LaravelLog($text, 'laravel.log', 0, 0);
126+
127+
assertEquals($expectedAdditionalText.' Example log entry for the level debug', $log->message);
128+
assertEquals($expectedAdditionalText.' Example log entry for the level debug', $log->getOriginalText());
129+
// got to make sure the rest of the data is still processed correctly!
130+
assertEquals('local', $log->extra['environment']);
131+
assertEquals(LaravelLogLevel::Debug, $log->level);
132+
});
133+
134+
it('finds the correct log level', function ($levelProvided, $levelExpected) {
135+
$text = "[2022-08-25 11:16:17] local.$levelProvided: Example log entry for the level debug";
136+
137+
$log = new LaravelLog($text, 'laravel.log', 0, 0);
138+
139+
assertEquals($levelExpected, $log->level);
140+
})->with([
141+
['INFO', LaravelLogLevel::Info],
142+
['DEBUG', LaravelLogLevel::Debug],
143+
['ERROR', LaravelLogLevel::Error],
144+
['WARNING', LaravelLogLevel::Warning],
145+
['CRITICAL', LaravelLogLevel::Critical],
146+
['ALERT', LaravelLogLevel::Alert],
147+
['EMERGENCY', LaravelLogLevel::Emergency],
148+
['info', LaravelLogLevel::Info],
149+
['iNfO', LaravelLogLevel::Info],
150+
['', LaravelLogLevel::None],
151+
]);
152+
153+
it('handles missing message', function () {
154+
$text = '[2022-11-07 17:51:33] production.ERROR: ';
155+
156+
$log = new LaravelLog($text, 'laravel.log', 0, 0);
157+
158+
assertEquals('2022-11-07 17:51:33', $log->datetime?->toDateTimeString());
159+
assertEquals(LaravelLogLevel::Error, $log->level);
160+
assertEquals('production', $log->extra['environment']);
161+
assertEquals('', $log->getOriginalText());
162+
});
163+
164+
it('strips extracted context when there\'s multiple contexts available', function () {
165+
config(['log-viewer.strip_extracted_context' => true]);
166+
$logText = <<<'EOF'
167+
[2023-08-16 14:00:25] testing.INFO: Test message. ["one","two"] {"memory_usage":"78 MB","process_id":1234}
168+
EOF;
169+
170+
$log = new LaravelLog($logText);
171+
172+
assertEquals('Test message.', $log->message);
173+
assertEquals(2, count($log->context));
174+
assertEquals(['one', 'two'], $log->context[0]);
175+
assertEquals(['memory_usage' => '78 MB', 'process_id' => 1234], $log->context[1]);
176+
});
177+
178+
it('correctly handles objects with number keys', function () {
179+
$logText = <<<'EOF'
180+
[2024-03-13 12:57:30] local.DEBUG: This is a log message {"array":{"10":"value1","20":"value2"}}
181+
EOF;
182+
183+
$log = new LaravelLog($logText);
184+
185+
assertEquals('This is a log message', $log->message);
186+
assertEquals(['array' => ['10' => 'value1', '20' => 'value2']], $log->context);
187+
});
188+
6189
it('can extract mail preview from a log', function () {
7190
$messageString = <<<'EOF'
8191
[2023-08-24 15:51:14] local.DEBUG: From: sender@example.com

‎tests/Unit/LogTest.php‎

Lines changed: 0 additions & 170 deletions
Original file line numberDiff line numberDiff line change
@@ -1,165 +1,9 @@
11
<?php
22

3-
use Opcodes\LogViewer\LogLevels\LaravelLogLevel;
43
use Opcodes\LogViewer\Logs\LaravelLog;
54

65
use function PHPUnit\Framework\assertEquals;
76

8-
it('can understand the default Laravel log format', function () {
9-
$text = '[2022-08-25 11:16:17] local.DEBUG: Example log entry for the level debug';
10-
11-
$log = new LaravelLog($text, $fileIdentifier = 'laravel.log', $filePosition = 5200, $index = 10);
12-
13-
assertEquals($index, $log->index);
14-
assertEquals(LaravelLogLevel::Debug, $log->level);
15-
assertEquals('local', $log->extra['environment']);
16-
assertEquals('2022-08-25 11:16:17', $log->datetime->toDateTimeString());
17-
assertEquals('Example log entry for the level debug', $log->message);
18-
assertEquals('Example log entry for the level debug', $log->getOriginalText());
19-
assertEquals($fileIdentifier, $log->fileIdentifier);
20-
assertEquals($filePosition, $log->filePosition);
21-
});
22-
23-
it('can understand multi-line logs', function () {
24-
$logText = <<<'EOF'
25-
Example log entry for the level debug
26-
with multiple lines of content.
27-
can contain dumped objects or JSON as well - it's all part of the contents.
28-
EOF;
29-
$text = '[2022-08-25 11:16:17] local.DEBUG: '.$logText;
30-
31-
$log = new LaravelLog($text, 'laravel.log', 0, 0);
32-
33-
assertEquals('Example log entry for the level debug', $log->message);
34-
assertEquals($logText, $log->getOriginalText());
35-
});
36-
37-
it('extracts JSON from the log text', function () {
38-
config(['log-viewer.strip_extracted_context' => true]);
39-
$logText = <<<'EOF'
40-
Example log entry for the level debug
41-
with multiple lines of content.
42-
{"one":1,"two":"two","three":[1,2,3]}
43-
can contain dumped objects or JSON as well - it's all part of the contents.
44-
EOF;
45-
$jsonString = '{"one":1,"two":"two","three":[1,2,3]}';
46-
$text = '[2022-08-25 11:16:17] local.DEBUG: '.$logText;
47-
48-
$log = new LaravelLog($text, 'laravel.log', 0, 0);
49-
50-
assertEquals('Example log entry for the level debug', $log->message);
51-
assertEquals(rtrim(str_replace($jsonString, '', $logText)), $log->getOriginalText());
52-
assertEquals(json_decode($jsonString, true), $log->context);
53-
});
54-
55-
it('extracts JSON, but does not remove from the log text if the config is set to false', function () {
56-
config(['log-viewer.strip_extracted_context' => false]);
57-
$logText = <<<'EOF'
58-
Example log entry for the level debug
59-
with multiple lines of content.
60-
{"one":1,"two":"two","three":[1,2,3]}
61-
can contain dumped objects or JSON as well - it's all part of the contents.
62-
EOF;
63-
$text = '[2022-08-25 11:16:17] local.DEBUG: '.$logText;
64-
65-
$log = new LaravelLog($text, 'laravel.log');
66-
67-
assertEquals('Example log entry for the level debug', $log->message);
68-
assertEquals($logText, $log->getOriginalText());
69-
assertEquals(json_decode('{"one":1,"two":"two","three":[1,2,3]}', true), $log->context);
70-
});
71-
72-
it('extracts JSON from a complex log', function () {
73-
config(['log-viewer.strip_extracted_context' => true]);
74-
$logText = <<<'EOF'
75-
Initiating facebook login.
76-
[HTTP request]
77-
*User ID:* guest
78-
*Request:* GET https://system.test/book/arunas/submit-facebook
79-
*Agent:* Mozilla/5.0 (iPhone; CPU iPhone OS 15_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/19G82 [FBAN/FBIOS;FBDV/iPhone9,3;FBMD/iPhone;FBSN/iOS;FBSV/15.6.1;FBSS/2;FBID/phone;FBLC/da_DK;FBOP/5]
80-
{"permalink":"arunas","session":{"_token":"BpqyiNyinnLamzer4jqzrh9NTyC6emFR41FitMpv","_previous":{"url":"https://system.test/book/arunas/center"},"_flash":{"old":[],"new":[]},"latest_permalink":"arunas"},"ip":"127.0.0.1","user_agent":"Mozilla/5.0 (iPhone; CPU iPhone OS 15_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/19G82 [FBAN/FBIOS;FBDV/iPhone9,3;FBMD/iPhone;FBSN/iOS;FBSV/15.6.1;FBSS/2;FBID/phone;FBLC/da_DK;FBOP/5]"}
81-
EOF;
82-
83-
$jsonString = '{"permalink":"arunas","session":{"_token":"BpqyiNyinnLamzer4jqzrh9NTyC6emFR41FitMpv","_previous":{"url":"https://system.test/book/arunas/center"},"_flash":{"old":[],"new":[]},"latest_permalink":"arunas"},"ip":"127.0.0.1","user_agent":"Mozilla/5.0 (iPhone; CPU iPhone OS 15_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/19G82 [FBAN/FBIOS;FBDV/iPhone9,3;FBMD/iPhone;FBSN/iOS;FBSV/15.6.1;FBSS/2;FBID/phone;FBLC/da_DK;FBOP/5]"}';
84-
$text = '[2022-08-25 11:16:17] local.DEBUG: '.$logText;
85-
86-
$log = new LaravelLog($text, 'laravel.log');
87-
88-
assertEquals('arunas', $log->context['permalink'] ?? null);
89-
assertEquals('Initiating facebook login.', $log->message);
90-
assertEquals(rtrim(str_replace($jsonString, '', $logText)), $log->getOriginalText());
91-
assertEquals(json_decode($jsonString, true), $log->context);
92-
});
93-
94-
it('can understand the optional microseconds in the timestamp', function () {
95-
$text = '[2022-08-25 11:16:17.125000] local.DEBUG: Example log entry for the level debug';
96-
97-
$log = new LaravelLog($text, 'laravel.log', 0, 0);
98-
99-
assertEquals(125000, $log->datetime->micro);
100-
});
101-
102-
it('can understand the optional time offset in the timestamp', function () {
103-
$text = '[2022-08-25 11:16:17.125000+02:00] local.DEBUG: Example log entry for the level debug';
104-
$expectedTimestamp = 1661418977;
105-
106-
$log = new LaravelLog($text, 'laravel.log', 0, 0);
107-
108-
assertEquals($expectedTimestamp, $log->datetime->timestamp);
109-
110-
// Meanwhile, if we switch the time offset an hour forward,
111-
// we can expect the timestamp to be reduced by 3600 seconds.
112-
$text = '[2022-08-25 11:16:17.125000+03:00] local.DEBUG: Example log entry for the level debug';
113-
$newExpectedTimestamp = $expectedTimestamp - 3600;
114-
115-
$log = new LaravelLog($text, 'laravel.log', 0, 0);
116-
117-
assertEquals($newExpectedTimestamp, $log->datetime->timestamp);
118-
});
119-
120-
it('can handle text in-between timestamp and environment/severity', function () {
121-
$text = '[2022-08-25 11:16:17] some additional text [!@#$%^&] and characters // !@#$ local.DEBUG: Example log entry for the level debug';
122-
$expectedAdditionalText = 'some additional text [!@#$%^&] and characters // !@#$';
123-
124-
$log = new LaravelLog($text, 'laravel.log', 0, 0);
125-
126-
assertEquals($expectedAdditionalText.' Example log entry for the level debug', $log->message);
127-
assertEquals($expectedAdditionalText.' Example log entry for the level debug', $log->getOriginalText());
128-
// got to make sure the rest of the data is still processed correctly!
129-
assertEquals('local', $log->extra['environment']);
130-
assertEquals(LaravelLogLevel::Debug, $log->level);
131-
});
132-
133-
it('finds the correct log level', function ($levelProvided, $levelExpected) {
134-
$text = "[2022-08-25 11:16:17] local.$levelProvided: Example log entry for the level debug";
135-
136-
$log = new LaravelLog($text, 'laravel.log', 0, 0);
137-
138-
assertEquals($levelExpected, $log->level);
139-
})->with([
140-
['INFO', LaravelLogLevel::Info],
141-
['DEBUG', LaravelLogLevel::Debug],
142-
['ERROR', LaravelLogLevel::Error],
143-
['WARNING', LaravelLogLevel::Warning],
144-
['CRITICAL', LaravelLogLevel::Critical],
145-
['ALERT', LaravelLogLevel::Alert],
146-
['EMERGENCY', LaravelLogLevel::Emergency],
147-
['info', LaravelLogLevel::Info],
148-
['iNfO', LaravelLogLevel::Info],
149-
['', LaravelLogLevel::None],
150-
]);
151-
152-
it('handles missing message', function () {
153-
$text = '[2022-11-07 17:51:33] production.ERROR: ';
154-
155-
$log = new LaravelLog($text, 'laravel.log', 0, 0);
156-
157-
assertEquals('2022-11-07 17:51:33', $log->datetime?->toDateTimeString());
158-
assertEquals(LaravelLogLevel::Error, $log->level);
159-
assertEquals('production', $log->extra['environment']);
160-
assertEquals('', $log->getOriginalText());
161-
});
162-
1637
it('can set a custom timezone of the log entry', function () {
1648
$text = '[2022-11-07 17:51:33] production.ERROR: test message';
1659
config(['log-viewer.timezone' => $tz = 'Europe/Vilnius']);
@@ -170,17 +14,3 @@
17014
$expectedTime = \Carbon\Carbon::parse('2022-11-07 17:51:33', 'UTC')->setTimezone($tz)->toDateTimeString();
17115
assertEquals($expectedTime, $log->datetime->toDateTimeString());
17216
});
173-
174-
it('strips extracted context when there\'s multiple contexts available', function () {
175-
config(['log-viewer.strip_extracted_context' => true]);
176-
$logText = <<<'EOF'
177-
[2023-08-16 14:00:25] testing.INFO: Test message. ["one","two"] {"memory_usage":"78 MB","process_id":1234}
178-
EOF;
179-
180-
$log = new LaravelLog($logText);
181-
182-
assertEquals('Test message.', $log->message);
183-
assertEquals(2, count($log->context));
184-
assertEquals(['one', 'two'], $log->context[0]);
185-
assertEquals(['memory_usage' => '78 MB', 'process_id' => 1234], $log->context[1]);
186-
});

0 commit comments

Comments
 (0)