refactor sdk/api logging (#1105)

brettmc · web-flow · commit ed65f22fff19 · 2023-08-31T09:39:33.000+10:00
send errors/warnings/etc by default through PHP's error_log. This gives more control to administrators, since error_log can
be configured to write to any stream (file, stderr, etc). I think it's also less surprising for people trying out otel (particularly
with development PHP settings, where trigger_error often breaks an application).
Adding a configuration value to control where logs go: OTEL_PHP_LOG_DESTINATION.
diff --git a/Behavior/Internal/LogWriter/ErrorLogWriter.php b/Behavior/Internal/LogWriter/ErrorLogWriter.php
@@ -0,0 +1,13 @@
+<?php
+
+declare(strict_types=1);
+
+namespace OpenTelemetry\API\Behavior\Internal\LogWriter;
+
+class ErrorLogWriter implements LogWriterInterface
+{
+    public function write($level, string $message, array $context): void
+    {
+        error_log(Formatter::format($level, $message, $context));
+    }
+}
diff --git a/Behavior/Internal/LogWriter/Formatter.php b/Behavior/Internal/LogWriter/Formatter.php
@@ -0,0 +1,37 @@
+<?php
+
+declare(strict_types=1);
+
+namespace OpenTelemetry\API\Behavior\Internal\LogWriter;
+
+class Formatter
+{
+    public static function format($level, string $message, array $context): string
+    {
+        $exception = (array_key_exists('exception', $context) && $context['exception'] instanceof \Throwable)
+            ? $context['exception']
+            : null;
+        if ($exception) {
+            $message = sprintf(
+                'OpenTelemetry: [%s] %s [exception] %s%s%s',
+                $level,
+                $message,
+                $exception->getMessage(),
+                PHP_EOL,
+                $exception->getTraceAsString()
+            );
+        } else {
+            //get calling location, skipping over trait, formatter etc
+            $caller = debug_backtrace()[3];
+            $message = sprintf(
+                'OpenTelemetry: [%s] %s in %s(%s)',
+                $level,
+                $message,
+                $caller['file'],
+                $caller['line'],
+            );
+        }
+
+        return $message;
+    }
+}
diff --git a/Behavior/Internal/LogWriter/LogWriterInterface.php b/Behavior/Internal/LogWriter/LogWriterInterface.php
@@ -0,0 +1,10 @@
+<?php
+
+declare(strict_types=1);
+
+namespace OpenTelemetry\API\Behavior\Internal\LogWriter;
+
+interface LogWriterInterface
+{
+    public function write($level, string $message, array $context): void;
+}
diff --git a/Behavior/Internal/LogWriter/NoopLogWriter.php b/Behavior/Internal/LogWriter/NoopLogWriter.php
@@ -0,0 +1,13 @@
+<?php
+
+declare(strict_types=1);
+
+namespace OpenTelemetry\API\Behavior\Internal\LogWriter;
+
+class NoopLogWriter implements LogWriterInterface
+{
+    public function write($level, string $message, array $context): void
+    {
+        //do nothing
+    }
+}
diff --git a/Behavior/Internal/LogWriter/Psr3LogWriter.php b/Behavior/Internal/LogWriter/Psr3LogWriter.php
@@ -0,0 +1,22 @@
+<?php
+
+declare(strict_types=1);
+
+namespace OpenTelemetry\API\Behavior\Internal\LogWriter;
+
+use Psr\Log\LoggerInterface;
+
+class Psr3LogWriter implements LogWriterInterface
+{
+    private LoggerInterface $logger;
+
+    public function __construct(LoggerInterface $logger)
+    {
+        $this->logger = $logger;
+    }
+
+    public function write($level, string $message, array $context): void
+    {
+        $this->logger->log($level, $message, $context);
+    }
+}
diff --git a/Behavior/Internal/LogWriter/StreamLogWriter.php b/Behavior/Internal/LogWriter/StreamLogWriter.php
@@ -0,0 +1,25 @@
+<?php
+
+declare(strict_types=1);
+
+namespace OpenTelemetry\API\Behavior\Internal\LogWriter;
+
+class StreamLogWriter implements LogWriterInterface
+{
+    private $stream;
+
+    public function __construct(string $destination)
+    {
+        $stream = fopen($destination, 'a');
+        if ($stream) {
+            $this->stream = $stream;
+        } else {
+            throw new \RuntimeException(sprintf('Unable to open %s for writing', $destination));
+        }
+    }
+
+    public function write($level, string $message, array $context): void
+    {
+        fwrite($this->stream, Formatter::format($level, $message, $context));
+    }
+}
diff --git a/Behavior/Internal/LogWriterFactory.php b/Behavior/Internal/LogWriterFactory.php
@@ -0,0 +1,57 @@
+<?php
+
+declare(strict_types=1);
+
+namespace OpenTelemetry\API\Behavior\Internal;
+
+use OpenTelemetry\API\Behavior\Internal\LogWriter\ErrorLogWriter;
+use OpenTelemetry\API\Behavior\Internal\LogWriter\LogWriterInterface;
+use OpenTelemetry\API\Behavior\Internal\LogWriter\NoopLogWriter;
+use OpenTelemetry\API\Behavior\Internal\LogWriter\Psr3LogWriter;
+use OpenTelemetry\API\Behavior\Internal\LogWriter\StreamLogWriter;
+use OpenTelemetry\API\Globals;
+use OpenTelemetry\API\LoggerHolder;
+
+class LogWriterFactory
+{
+    private const OTEL_PHP_LOG_DESTINATION = 'OTEL_PHP_LOG_DESTINATION';
+
+    public function create(): LogWriterInterface
+    {
+        $dest = Globals::configurationResolver()->getEnum(self::OTEL_PHP_LOG_DESTINATION);
+        //we might not have an SDK, so attempt to get from environment
+        if (!$dest) {
+            $dest = array_key_exists(self::OTEL_PHP_LOG_DESTINATION, $_SERVER)
+                ? $_SERVER[self::OTEL_PHP_LOG_DESTINATION]
+                : getenv(self::OTEL_PHP_LOG_DESTINATION);
+        }
+        if (!$dest) {
+            $dest = ini_get(self::OTEL_PHP_LOG_DESTINATION);
+        }
+        $logger = LoggerHolder::get();
+
+        switch ($dest) {
+            case 'none':
+                return new NoopLogWriter();
+            case 'stderr':
+                return new StreamLogWriter('php://stderr');
+            case 'stdout':
+                return new StreamLogWriter('php://stdout');
+            case 'psr3':
+                if ($logger) {
+                    return new Psr3LogWriter($logger);
+                }
+                error_log('OpenTelemetry: cannot use OTEL_PHP_LOG_DESTINATION=psr3 without providing a PSR-3 logger');
+                //default to error log
+                return new ErrorLogWriter();
+            case 'error_log':
+                return new ErrorLogWriter();
+            default:
+                if ($logger) {
+                    return new Psr3LogWriter($logger);
+                }
+
+                return new ErrorLogWriter();
+        }
+    }
+}
diff --git a/Behavior/Internal/Logging.php b/Behavior/Internal/Logging.php
@@ -4,16 +4,17 @@
 
 namespace OpenTelemetry\API\Behavior\Internal;
 
+use OpenTelemetry\API\Behavior\Internal\LogWriter\LogWriterInterface;
 use Psr\Log\LogLevel;
 
 /**
- * Logging utility functions for default (error_log) logging.
+ * Logging utility functions for internal logging (of OpenTelemetry errors/warnings etc).
  * This is not part of SDK configuration to avoid creating a dependency on SDK from any package which does logging.
  * @todo this should be `@internal`, but deptrac is not happy with that.
  */
 class Logging
 {
-    private const VARIABLE_NAME = 'OTEL_LOG_LEVEL';
+    private const OTEL_LOG_LEVEL = 'OTEL_LOG_LEVEL';
     private const DEFAULT_LEVEL = LogLevel::INFO;
     private const NONE = 'none';
     private const LEVELS = [
@@ -32,6 +33,19 @@ class Logging
      * The minimum log level. Messages with lower severity than this will be ignored.
      */
     private static ?int $logLevel = null;
+    private static ?LogWriterInterface $writer = null;
+
+    public static function setLogWriter(LogWriterInterface $writer): void
+    {
+        self::$writer = $writer;
+    }
+
+    public static function logWriter(): LogWriterInterface
+    {
+        self::$writer ??= (new LogWriterFactory())->create();
+
+        return self::$writer;
+    }
 
     /**
      * Get level priority from level name
@@ -53,30 +67,13 @@ public static function logLevel(): int
         return self::$logLevel;
     }
 
-    /**
-     * Map PSR-3 levels to error_log levels.
-     * Note that we should never use higher than E_USER_WARNING so that we do not break user applications.
-     */
-    public static function map(string $level)
-    {
-        switch ($level) {
-            case LogLevel::WARNING:
-            case LogLevel::ERROR:
-            case LogLevel::CRITICAL:
-            case LogLevel::EMERGENCY:
-                return E_USER_WARNING;
-            default:
-                return E_USER_NOTICE;
-        }
-    }
-
     private static function getLogLevel(): int
     {
-        $level = array_key_exists(self::VARIABLE_NAME, $_SERVER)
-            ? $_SERVER[self::VARIABLE_NAME]
-            : getenv(self::VARIABLE_NAME);
+        $level = array_key_exists(self::OTEL_LOG_LEVEL, $_SERVER)
+            ? $_SERVER[self::OTEL_LOG_LEVEL]
+            : getenv(self::OTEL_LOG_LEVEL);
         if (!$level) {
-            $level = ini_get(self::VARIABLE_NAME);
+            $level = ini_get(self::OTEL_LOG_LEVEL);
         }
         if (!$level) {
             $level = self::DEFAULT_LEVEL;
@@ -88,5 +85,6 @@ private static function getLogLevel(): int
     public static function reset(): void
     {
         self::$logLevel = null;
+        self::$writer = null;
     }
 }
diff --git a/Behavior/LogsMessagesTrait.php b/Behavior/LogsMessagesTrait.php
@@ -5,7 +5,6 @@
 namespace OpenTelemetry\API\Behavior;
 
 use OpenTelemetry\API\Behavior\Internal\Logging;
-use OpenTelemetry\API\LoggerHolder;
 use Psr\Log\LogLevel;
 
 trait LogsMessagesTrait
@@ -17,33 +16,10 @@ private static function shouldLog(string $level): bool
 
     private static function doLog(string $level, string $message, array $context): void
     {
-        $logger = LoggerHolder::get();
-        if ($logger !== null) {
+        $writer = Logging::logWriter();
+        if (self::shouldLog($level)) {
             $context['source'] = get_called_class();
-            $logger->log($level, $message, $context);
-        } elseif (self::shouldLog($level)) {
-            $exception = (array_key_exists('exception', $context) && $context['exception'] instanceof \Throwable)
-            ? $context['exception']
-            : null;
-            if ($exception) {
-                $message = sprintf(
-                    '%s: %s%s%s',
-                    $message,
-                    $exception->getMessage(),
-                    PHP_EOL,
-                    $exception->getTraceAsString()
-                );
-            } else {
-                //get calling location, skipping over trait
-                $caller = debug_backtrace()[1];
-                $message = sprintf(
-                    '%s(%s): %s',
-                    $caller['file'],
-                    $caller['line'],
-                    $message,
-                );
-            }
-            trigger_error($message, Logging::map($level));
+            $writer->write($level, $message, $context);
         }
     }
 
diff --git a/Instrumentation/ConfigurationResolverInterface.php b/Instrumentation/ConfigurationResolverInterface.php
@@ -11,4 +11,5 @@ public function getString(string $name): ?string;
     public function getBoolean(string $name): ?bool;
     public function getInt(string $name): ?int;
     public function getList(string $name): array;
+    public function getEnum(string $name): ?string;
 }
diff --git a/Instrumentation/NoopConfigurationResolver.php b/Instrumentation/NoopConfigurationResolver.php
@@ -30,4 +30,9 @@ public function getList(string $name): array
     {
         return [];
     }
+
+    public function getEnum(string $name): ?string
+    {
+        return null;
+    }
 }

Original file line number	Diff line number	Diff line change
`@@ -11,4 +11,5 @@ public function getString(string $name): ?string;`
`11`	`11`	`public function getBoolean(string $name): ?bool;`
`12`	`12`	`public function getInt(string $name): ?int;`
`13`	`13`	`public function getList(string $name): array;`
	`14`	`+ public function getEnum(string $name): ?string;`
`14`	`15`	`}`