open-telemetry / opentelemetry-php

The OpenTelemetry PHP Library
https://opentelemetry.io/docs/instrumentation/php/
Apache License 2.0
715 stars 174 forks source link

Missing logs from opentelemetry-auto-psr3 #1374

Open NeilWhitworth opened 2 weeks ago

NeilWhitworth commented 2 weeks ago

Describe your environment PHP 8.3.8 (cli) (built: Jun 6 2024 17:04:22) (NTS) Symfony (6.4) based application open-telemetry/opentelemetry-auto-psr3 v 0.0.6 OTEL_PHP_PSR3_MODE=export

Steps to reproduce Call psr logger with a simple array as $context

$var1 = 'hello';
$var2 = 'world';

$this->logger->info('This works fine');
$this->logger->info('So does this', ['var1' => $var1, 'var2' => $var2]);
$this->logger->error('This goes missing', [$var1, $var2]);

What is the expected behavior? All log record to be exported

What is the actual behavior? The first 2 log records are exported and visible, but the 3rd disappears

Additional context

From Psr3Instrumentation.php

                    $record = (new API\LogRecord($body))
                        ->setSeverityNumber(API\Map\Psr3::severityNumber($level))
                        ->setAttributes(Formatter::format($context));        //<< this line fails as LogRecord::setAttribute expects a string, but $context is a simple php array with integer indexes
                    $instrumentation->logger()->emit($record);
brettmc commented 1 week ago

Hi @NeilWhitworth thanks for the bug report. When $context is a numerically-indexed array, what do you think should be the attribute keys? Should we just cast them to strings, eg 0, 1, etc? edit: or, should those attributes be dropped but the log still exported?

NeilWhitworth commented 1 week ago

Hi, The attributes should be kept as they will often contain useful information. As to what key name should be used I don't know. Simply casting to strings as 0, 1, etc is quick and simple, but feels incorrect, Perhaps prefix with context. so they end up as context.0, context.1 etc?

brettmc commented 6 days ago

Question from SIG: what does monolog do with context without keys? That might be a good basis for what we should do...

NeilWhitworth commented 6 days ago

Using monolog's JSON formatter, the context is either a JOSN object

{"message":"This works fine","context":{},"level":200,"level_name":"INFO","channel":"app","datetime":"2024-09-11T13:24:25.302904+00:00","extra":{}} {"message":"So does this","context":{"var1":42,"var2":"Hello World"},"level":200,"level_name":"INFO","channel":"app","datetime":"2024-09-11T13:24:25.303441+00:00","extra":{}}

or a simple JSON array

{"message":"This goes missing","context":[42,"Hello World"],"level":400,"level_name":"ERROR","channel":"app","datetime":"2024-09-11T13:24:25.303860+00:00","extra":{}}

When using the line formatter

[2024-09-11T13:34:17.189264+00:00] app.INFO: This works fine [] [] [2024-09-11T13:34:17.189583+00:00] app.INFO: So does this {"var1":42,"var2":"Hello World"} [] [2024-09-11T13:34:17.189785+00:00] app.ERROR: This goes missing [42,"Hello World"] []

ChrisLightfootWild commented 6 days ago

That looks like a list just gets stringified under the context key.

Maybe we should use the PHP 8.1 array_is_list function and, given the check returns true, the formatter could maybe build out context implicitly 'context' => (string) $context.