Add console sink to the diagnostic logging (open-telemetry#3558)

* Add console logger sink

* cleanup

* remove container detection

* add unit tests

* add managed logs output tests

* update tests

* Update docs

* refactor CreateSink

* refactor LoggerImpl

* reset whitespace

* fix native logger

---------

Co-authored-by: Rajkumar Rangaraj <[email protected]>
Co-authored-by: Paulo Janotti <[email protected]>

Author: 3 people

CHANGELOG.md

@@ -32,6 +32,8 @@ This component adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.h
   - `OTEL_EXPORTER_OTLP_LOGS_PROTOCOL`.
 - Support for air-gapped installations through `DOWNLOAD_DIR` or `LOCAL_PATH`
   arguments to `otel-dotnet-auto-install.sh`.
+- Added `OTEL_DOTNET_AUTO_LOGGER` to select preferred sink for AutoInstrumentation
+  diagnostic logs.
 
 ### Changed
 

docs/config.md

@@ -58,6 +58,7 @@ However, if given setting supports it, then:
 | `OTEL_DOTNET_AUTO_HOME`              | Installation location.                                                                                                                                                                                                                  |               | [Experimental](https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/versioning-and-stability.md) |
 | `OTEL_DOTNET_AUTO_EXCLUDE_PROCESSES` | Names of the executable files that the profiler cannot instrument. Supports multiple comma-separated values, for example: `ReservedProcess.exe,powershell.exe`. If unset, the profiler attaches to all processes by default. \[1\]\[2\] |               | [Experimental](https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/versioning-and-stability.md) |
 | `OTEL_DOTNET_AUTO_FAIL_FAST_ENABLED` | Enables possibility to fail process when automatic instrumentation cannot be executed. It is designed for debugging purposes. It should not be used in production environment. \[1\]                                                    | `false`       | [Experimental](https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/versioning-and-stability.md) |
+| `OTEL_DOTNET_AUTO_LOGGER`            | AutoInstrumentation diagnostic logs sink. (supported values: `none`,`file`,`console`)                                                                                                                                                   | `file`        | [Experimental](https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/versioning-and-stability.md) |
 | `OTEL_LOG_LEVEL`                     | SDK log level. (supported values: `none`,`error`,`warn`,`info`,`debug`)                                                                                                                                                                 | `info`        | [Stable](https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/versioning-and-stability.md)       |
 
 \[1\] If `OTEL_DOTNET_AUTO_FAIL_FAST_ENABLED` is set to `true` then processes

src/OpenTelemetry.AutoInstrumentation.Loader/OpenTelemetry.AutoInstrumentation.Loader.csproj

@@ -16,6 +16,9 @@
   <Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\NoopLogger.cs">
     <Link>Logging\NoopLogger.cs</Link>
   </Compile>
+  <Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\ConsoleSink.cs">
+    <Link>Logging\ConsoleSink.cs</Link>
+  </Compile>
   <Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\FileSink.cs">
     <Link>Logging\FileSink.cs</Link>
   </Compile>
@@ -43,6 +46,9 @@
   <Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\LogLevel.cs">
     <Link>Logging\LogLevel.cs</Link>
   </Compile>
+  <Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\LogSink.cs">
+    <Link>Logging\LogSink.cs</Link>
+  </Compile>
   <Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\NoopSink.cs">
     <Link>Logging\NoopSink.cs</Link>
   </Compile>

src/OpenTelemetry.AutoInstrumentation.Native/environment_variables.h

@@ -14,6 +14,9 @@ namespace environment {
 // Sets logging level used by autoinstrumentation loggers
 const WSTRING log_level = WStr("OTEL_LOG_LEVEL");
 
+// Sets logger used by autoinstrumentation
+const WSTRING log_sink = WStr("OTEL_DOTNET_AUTO_LOGGER");
+
 // Sets max size of a single log file
 const WSTRING max_log_file_size = WStr("OTEL_DOTNET_AUTO_LOG_FILE_SIZE");
 

src/OpenTelemetry.AutoInstrumentation.Native/logger_impl.h

@@ -12,6 +12,7 @@
 
 #include "spdlog/sinks/null_sink.h"
 #include "spdlog/sinks/rotating_file_sink.h"
+#include "spdlog/sinks/stdout_sinks.h"
 
 #ifndef _WIN32
 typedef struct stat Stat;
@@ -34,6 +35,7 @@ class LoggerImpl : public Singleton<LoggerImpl<TLoggerPolicy>>
 private:
     std::shared_ptr<spdlog::logger> m_fileout;
     static std::string GetLogPath(const std::string& file_name_suffix);
+    static std::shared_ptr<spdlog::logger> CreateFileSink(std::string logger_name);
     LoggerImpl();
     ~LoggerImpl();
 
@@ -43,6 +45,10 @@ class LoggerImpl : public Singleton<LoggerImpl<TLoggerPolicy>>
     static inline const WSTRING log_level_info  = WStr("info");
     static inline const WSTRING log_level_debug = WStr("debug");
 
+    static inline const WSTRING log_sink_none    = WStr("none");
+    static inline const WSTRING log_sink_file    = WStr("file");
+    static inline const WSTRING log_sink_console = WStr("console");
+
     static inline const std::string logger_name = "Logger";
 
     bool ShouldLog(spdlog::level::level_enum log_level);
@@ -93,6 +99,38 @@ std::string LoggerImpl<TLoggerPolicy>::GetLogPath(const std::string& file_name_s
     return path;
 }
 
+template <typename TLoggerPolicy>
+std::shared_ptr<spdlog::logger> LoggerImpl<TLoggerPolicy>::CreateFileSink(std::string logger_name)
+{
+    static auto current_process_name = ToString(GetCurrentProcessName());
+    static auto current_process_id   = GetPID();
+    static auto current_process_without_extension =
+        current_process_name.substr(0, current_process_name.find_last_of("."));
+
+    static auto file_name_suffix =
+        std::to_string(current_process_id) + "-" + current_process_without_extension + "-Native";
+
+    // by default, use the same size as on managed side: 10MiB
+    static auto file_size = GetConfiguredSize(environment::max_log_file_size, 10485760);
+
+    static std::shared_ptr<spdlog::logger> fileout;
+
+    try
+    {
+        fileout = spdlog::rotating_logger_mt(logger_name, GetLogPath(file_name_suffix), file_size, 10);
+    }
+    catch (...)
+    {
+        // By writing into the stderr was changing the behavior in a CI scenario.
+        // There's not a good way to report errors when trying to create the log file.
+        // But we never should be changing the normal behavior of an app.
+        // std::cerr << "LoggerImpl Handler: Error creating native log file." << std::endl;
+        fileout = spdlog::null_logger_mt(logger_name);
+    }
+
+    return fileout;
+}
+
 template <typename TLoggerPolicy>
 LoggerImpl<TLoggerPolicy>::LoggerImpl()
 {
@@ -131,28 +169,22 @@ LoggerImpl<TLoggerPolicy>::LoggerImpl()
 
     spdlog::flush_every(std::chrono::seconds(3));
 
-    static auto current_process_name = ToString(GetCurrentProcessName());
-    static auto current_process_id   = GetPID();
-    static auto current_process_without_extension =
-        current_process_name.substr(0, current_process_name.find_last_of("."));
+    static auto configured_log_sink = GetEnvironmentValue(environment::log_sink);
 
-    static auto file_name_suffix =
-        std::to_string(current_process_id) + "-" + current_process_without_extension + "-Native";
-
-    // by default, use the same size as on managed side: 10MiB
-    static auto file_size        = GetConfiguredSize(environment::max_log_file_size, 10485760);
-
-    try
+    if (configured_log_sink == log_sink_none)
     {
-        m_fileout = spdlog::rotating_logger_mt(logger_name, GetLogPath(file_name_suffix), file_size, 10);
+        m_fileout = spdlog::null_logger_mt(logger_name);
+        return;
     }
-    catch (...)
+    else if (configured_log_sink == log_sink_console)
     {
-        // By writing into the stderr was changing the behavior in a CI scenario.
-        // There's not a good way to report errors when trying to create the log file.
-        // But we never should be changing the normal behavior of an app.
-        // std::cerr << "LoggerImpl Handler: Error creating native log file." << std::endl;
-        m_fileout = spdlog::null_logger_mt(logger_name);
+        m_fileout = spdlog::stdout_logger_mt(logger_name);
+    }
+    // Default to file sink
+    else
+    {
+        // Creates file sink, if file sink creation fails fallbacks to NoOp sink.
+        m_fileout = CreateFileSink(logger_name);
     }
 
     m_fileout->set_level(log_level);
@@ -237,7 +269,7 @@ void LoggerImpl<TLoggerPolicy>::Error(const Args&... args)
 }
 
 template <typename TLoggerPolicy>
-template< typename... Args>
+template <typename... Args>
 void LoggerImpl<TLoggerPolicy>::Critical(const Args&... args)
 {
     // to avoid possibly unnecessary LogToString conversion, check log level before calling underlying logger
@@ -259,13 +291,12 @@ void LoggerImpl<TLoggerPolicy>::Flush()
     m_fileout->flush();
 }
 
-
 template <typename TLoggerPolicy>
 bool LoggerImpl<TLoggerPolicy>::IsDebugEnabled() const
 {
     return m_fileout->level() == spdlog::level::debug;
 }
 
-} // namespace shared
+} // namespace trace
 
 #endif // OTEL_CLR_PROFILER_LOGGER_IMPL_H_

src/OpenTelemetry.AutoInstrumentation.StartupHook/OpenTelemetry.AutoInstrumentation.StartupHook.csproj

@@ -16,6 +16,9 @@
     <Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\NoopLogger.cs">
       <Link>Logging\NoopLogger.cs</Link>
     </Compile>
+    <Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\ConsoleSink.cs">
+      <Link>Logging\ConsoleSink.cs</Link>
+    </Compile>
     <Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\FileSink.cs">
       <Link>Logging\FileSink.cs</Link>
     </Compile>
@@ -43,6 +46,9 @@
     <Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\LogLevel.cs">
       <Link>Logging\LogLevel.cs</Link>
     </Compile>
+    <Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\LogSink.cs">
+      <Link>Logging\LogSink.cs</Link>
+    </Compile>
     <Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\NoopSink.cs">
       <Link>Logging\NoopSink.cs</Link>
     </Compile>

src/OpenTelemetry.AutoInstrumentation/Constants.cs

@@ -63,6 +63,12 @@ public static class LogLevel
             public const string Information = "info";
             public const string Debug = "debug";
         }
+
+        public static class Loggers
+        {
+            public const string File = "file";
+            public const string Console = "console";
+        }
     }
 
     public static class EnvironmentVariables

src/OpenTelemetry.AutoInstrumentation/Logging/ConsoleSink.cs

@@ -0,0 +1,19 @@
+// Copyright The OpenTelemetry Authors
+// SPDX-License-Identifier: Apache-2.0
+
+namespace OpenTelemetry.AutoInstrumentation.Logging;
+
+internal class ConsoleSink : ISink
+{
+    private readonly string _source;
+
+    public ConsoleSink(string source)
+    {
+        _source = source;
+    }
+
+    public void Write(string message)
+    {
+        Console.WriteLine($"[{_source}] {message}");
+    }
+}

src/OpenTelemetry.AutoInstrumentation/Logging/IOtelLogger.cs

@@ -3,7 +3,7 @@
 
 namespace OpenTelemetry.AutoInstrumentation.Logging;
 
-internal interface IOtelLogger
+internal interface IOtelLogger : IDisposable
 {
     LogLevel Level { get; }
 

src/OpenTelemetry.AutoInstrumentation/Logging/InternalLogger.cs

@@ -142,6 +142,14 @@ public void Error<T0, T1, T2>(Exception exception, string messageTemplate, T0 pr
     public void Error(Exception exception, string messageTemplate, object[] args, bool writeToEventLog)
         => Write(LogLevel.Error, exception, messageTemplate, args, writeToEventLog);
 
+    public void Dispose()
+    {
+        if (_sink is IDisposable disposableSink)
+        {
+            disposableSink.Dispose();
+        }
+    }
+
     private static void WriteEventSourceLog(LogLevel level, string message)
     {
         switch (level)

src/OpenTelemetry.AutoInstrumentation/Logging/LogSink.cs

@@ -0,0 +1,25 @@
+// Copyright The OpenTelemetry Authors
+// SPDX-License-Identifier: Apache-2.0
+
+namespace OpenTelemetry.AutoInstrumentation.Logging;
+
+/// <summary>
+/// Specifies the target sink.
+/// </summary>
+internal enum LogSink
+{
+    /// <summary>
+    /// File sink.
+    /// </summary>
+    File,
+
+    /// <summary>
+    /// Std out or Console sink.
+    /// </summary>
+    Console,
+
+    /// <summary>
+    /// No op sink or null sink.
+    /// </summary>
+    NoOp
+}

src/OpenTelemetry.AutoInstrumentation/Logging/NoopLogger.cs

@@ -180,4 +180,8 @@ public void Error<T0, T1, T2>(Exception exception, string messageTemplate, T0 pr
     public void Error(Exception exception, string messageTemplate, object[] args, bool writeToEventLog = true)
     {
     }
+
+    public void Dispose()
+    {
+    }
 }