Configurable log level - native code and loader (#2288)

* handle configured log level in native code and loader

* dotnet format

* remove benchmark for removed logger

* update build after benchmark removal

* docs update

* update changelog after OTEL_DOTNET_AUTO_DEBUG removal

* extract log level consts

* Update CHANGELOG.md

Co-authored-by: Robert Pająk <pellared@hotmail.com>

* static inline consts

* pr feedback

---------

Co-authored-by: Robert Pająk <pellared@hotmail.com>
This commit is contained in:
Mateusz Łach 2023-03-07 18:05:42 +01:00 committed by GitHub
parent e81ae556e3
commit 61df3cb24e
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
21 changed files with 152 additions and 362 deletions

View File

@ -9,12 +9,16 @@ This component adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.h
### Added ### Added
- Support `OTEL_LOG_LEVEL` to configure SDK logging level.
### Changed ### Changed
### Deprecated ### Deprecated
### Removed ### Removed
- Remove support for enabling debugging mode with `OTEL_DOTNET_AUTO_DEBUG`.
### Fixed ### Fixed
### Security ### Security

View File

@ -23,7 +23,7 @@ with environment variables taking precedence over `App.config` or `Web.config` f
- `OTEL_DOTNET_AUTO_INTEGRATIONS_FILE` - `OTEL_DOTNET_AUTO_INTEGRATIONS_FILE`
- `OTEL_DOTNET_AUTO_[TRACES|METRICS|LOGS]_[ENABLED|DISABLED]_INSTRUMENTATIONS` - `OTEL_DOTNET_AUTO_[TRACES|METRICS|LOGS]_[ENABLED|DISABLED]_INSTRUMENTATIONS`
- `OTEL_DOTNET_AUTO_LOG_DIRECTORY` - `OTEL_DOTNET_AUTO_LOG_DIRECTORY`
- `OTEL_DOTNET_AUTO_DEBUG` - `OTEL_LOG_LEVEL`
- `OTEL_DOTNET_AUTO_NETFX_REDIRECT_ENABLED` - `OTEL_DOTNET_AUTO_NETFX_REDIRECT_ENABLED`
Example with `OTEL_SERVICE_NAME` setting: Example with `OTEL_SERVICE_NAME` setting:
@ -48,6 +48,7 @@ However, if given setting supports it, then:
|--------------------------------------|------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------|---------------| |--------------------------------------|------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------|---------------|
| `OTEL_DOTNET_AUTO_HOME` | Installation location. | | | `OTEL_DOTNET_AUTO_HOME` | Installation location. | |
| `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. | | | `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. | |
| `OTEL_LOG_LEVEL` | SDK log level. (supported values: `none`,`error`,`warn`,`info`,`debug`) | `info` |
## Resources ## Resources
@ -364,9 +365,9 @@ the instrumentation uses the path of the current user's [temporary folder](https
instead. instead.
| Environment variable | Description | Default value | | Environment variable | Description | Default value |
|-----------------------------------------------------|---------------------------------------------------------|------------------------------------------| |-----------------------------------------------------|-------------------------------------------------------------------------|------------------------------------------|
| `OTEL_DOTNET_AUTO_LOG_DIRECTORY` | Directory of the .NET Tracer logs. | _See the previous note on default paths_ | | `OTEL_DOTNET_AUTO_LOG_DIRECTORY` | Directory of the .NET Tracer logs. | _See the previous note on default paths_ |
| `OTEL_DOTNET_AUTO_DEBUG` | Enables debugging mode for the tracer. | `false` | | `OTEL_LOG_LEVEL` | SDK log level. (supported values: `none`,`error`,`warn`,`info`,`debug`) | `info` |
| `OTEL_DOTNET_AUTO_TRACES_CONSOLE_EXPORTER_ENABLED` | Whether the traces console exporter is enabled or not. | `false` | | `OTEL_DOTNET_AUTO_TRACES_CONSOLE_EXPORTER_ENABLED` | Whether the traces console exporter is enabled or not. | `false` |
| `OTEL_DOTNET_AUTO_METRICS_CONSOLE_EXPORTER_ENABLED` | Whether the metrics console exporter is enabled or not. | `false` | | `OTEL_DOTNET_AUTO_METRICS_CONSOLE_EXPORTER_ENABLED` | Whether the metrics console exporter is enabled or not. | `false` |
| `OTEL_DOTNET_AUTO_LOGS_CONSOLE_EXPORTER_ENABLED` | Whether the logs console exporter is enabled or not. | `false` | | `OTEL_DOTNET_AUTO_LOGS_CONSOLE_EXPORTER_ENABLED` | Whether the logs console exporter is enabled or not. | `false` |

View File

@ -96,14 +96,14 @@ Detailed debug logs can help you troubleshoot instrumentation issues, and can be
attached to issues in this project to facilitate investigation. attached to issues in this project to facilitate investigation.
To get the detailed logs from the OpenTelemetry .NET Automatic Instrumentation, set To get the detailed logs from the OpenTelemetry .NET Automatic Instrumentation, set
the `OTEL_DOTNET_AUTO_DEBUG` environment variable to `true` before the the `OTEL_LOG_LEVEL` environment variable to `debug` before the
instrumented process starts. instrumented process starts.
By default, the library writes the log files under predefined locations. If needed, By default, the library writes the log files under predefined locations. If needed,
change the default location by updating the `OTEL_DOTNET_AUTO_LOG_DIRECTORY` change the default location by updating the `OTEL_DOTNET_AUTO_LOG_DIRECTORY`
environment variable. environment variable.
After obtaining the logs, remove the `OTEL_DOTNET_AUTO_DEBUG` After obtaining the logs, remove the `OTEL_LOG_LEVEL`
environment variable to avoid unnecessary overhead. environment variable to avoid unnecessary overhead.
## Nothing happens ## Nothing happens

View File

@ -0,0 +1,25 @@
// <copyright file="AutoInstrumentationEventSource.Name.cs" company="OpenTelemetry Authors">
// Copyright The OpenTelemetry Authors
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
// </copyright>
using System.Diagnostics.Tracing;
// ReSharper disable once CheckNamespace
namespace OpenTelemetry.AutoInstrumentation;
[EventSource(Name = "OpenTelemetry-AutoInstrumentation-Loader")]
internal partial class AutoInstrumentationEventSource
{
}

View File

@ -1,70 +0,0 @@
//------------------------------------------------------------------------------
// <auto-generated />
// This comment is here to prevent StyleCop from analyzing a file originally from Serilog.
//------------------------------------------------------------------------------
// Copyright 2013-2019 Serilog Contributors
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
// Modified by OpenTelemetry Authors.
using System.Text;
namespace OpenTelemetry.AutoInstrumentation.Loader
{
internal sealed class FileSink : IDisposable
{
readonly TextWriter _output;
readonly FileStream _underlyingStream;
readonly object _syncRoot = new object();
public FileSink(string path, Encoding encoding = null)
{
if (path == null) throw new ArgumentNullException(nameof(path));
var directory = Path.GetDirectoryName(path);
if (!string.IsNullOrWhiteSpace(directory) && !Directory.Exists(directory))
{
Directory.CreateDirectory(directory);
}
Stream outputStream = _underlyingStream = System.IO.File.Open(path, FileMode.Append, FileAccess.Write, FileShare.Read);
_output = new StreamWriter(outputStream, encoding ?? new UTF8Encoding(encoderShouldEmitUTF8Identifier: false));
}
public void Info(string message, params object[] args)
{
_output.Write(message, args);
FlushToDisk();
}
public void Dispose()
{
lock (_syncRoot)
{
_output.Dispose();
}
}
private void FlushToDisk()
{
lock (_syncRoot)
{
_output.Flush();
_underlyingStream.Flush(true);
}
}
}
}

View File

@ -61,12 +61,12 @@ internal partial class Loader
// load the originally referenced version // load the originally referenced version
if (assemblyName.Name != null && assemblyName.Name.StartsWith("OpenTelemetry.AutoInstrumentation", StringComparison.OrdinalIgnoreCase) && File.Exists(path)) if (assemblyName.Name != null && assemblyName.Name.StartsWith("OpenTelemetry.AutoInstrumentation", StringComparison.OrdinalIgnoreCase) && File.Exists(path))
{ {
LoaderLogger.Debug("Loading {0} with Assembly.LoadFrom", path); Logger.Debug("Loading {0} with Assembly.LoadFrom", path);
return Assembly.LoadFrom(path); return Assembly.LoadFrom(path);
} }
else if (File.Exists(path)) else if (File.Exists(path))
{ {
LoaderLogger.Debug("Loading {0} with DependencyLoadContext.LoadFromAssemblyPath", path); Logger.Debug("Loading {0} with DependencyLoadContext.LoadFromAssemblyPath", path);
return DependencyLoadContext.LoadFromAssemblyPath(path); // Load unresolved framework and third-party dependencies into a custom Assembly Load Context return DependencyLoadContext.LoadFromAssemblyPath(path); // Load unresolved framework and third-party dependencies into a custom Assembly Load Context
} }

View File

@ -46,19 +46,19 @@ internal partial class Loader
return null; return null;
} }
LoaderLogger.Debug("Requester [{0}] requested [{1}]", args?.RequestingAssembly?.FullName ?? "<null>", args?.Name ?? "<null>"); Logger.Debug("Requester [{0}] requested [{1}]", args?.RequestingAssembly?.FullName ?? "<null>", args?.Name ?? "<null>");
var path = Path.Combine(ManagedProfilerDirectory, $"{assemblyName}.dll"); var path = Path.Combine(ManagedProfilerDirectory, $"{assemblyName}.dll");
if (File.Exists(path)) if (File.Exists(path))
{ {
try try
{ {
var loadedAssembly = Assembly.LoadFrom(path); var loadedAssembly = Assembly.LoadFrom(path);
LoaderLogger.Debug("Assembly.LoadFrom(\"{0}\") succeeded={1}", path, loadedAssembly != null); Logger.Debug<string, bool>("Assembly.LoadFrom(\"{0}\") succeeded={1}", path, loadedAssembly != null);
return loadedAssembly; return loadedAssembly;
} }
catch (Exception ex) catch (Exception ex)
{ {
LoaderLogger.Debug("Assembly.LoadFrom(\"{0}\") Exception: {1}", path, ex); Logger.Debug(ex, "Assembly.LoadFrom(\"{0}\") Exception: {1}", path, ex.Message);
} }
} }

View File

@ -15,6 +15,7 @@
// </copyright> // </copyright>
using System.Reflection; using System.Reflection;
using OpenTelemetry.AutoInstrumentation.Logging;
namespace OpenTelemetry.AutoInstrumentation.Loader; namespace OpenTelemetry.AutoInstrumentation.Loader;
@ -25,6 +26,8 @@ internal partial class Loader
{ {
private static readonly string ManagedProfilerDirectory; private static readonly string ManagedProfilerDirectory;
private static readonly IOtelLogger Logger = OtelLogging.GetLogger("Loader");
/// <summary> /// <summary>
/// Initializes static members of the <see cref="Loader"/> class. /// Initializes static members of the <see cref="Loader"/> class.
/// This method also attempts to load the OpenTelemetry.AutoInstrumentation .NET assembly. /// This method also attempts to load the OpenTelemetry.AutoInstrumentation .NET assembly.
@ -39,7 +42,7 @@ internal partial class Loader
} }
catch (Exception ex) catch (Exception ex)
{ {
LoaderLogger.Log(ex, "Unable to register a callback to the CurrentDomain.AssemblyResolve event."); Logger.Error(ex, "Unable to register a callback to the CurrentDomain.AssemblyResolve event.");
} }
TryLoadManagedAssembly(); TryLoadManagedAssembly();
@ -47,7 +50,7 @@ internal partial class Loader
private static void TryLoadManagedAssembly() private static void TryLoadManagedAssembly()
{ {
LoaderLogger.Log("Managed Loader TryLoadManagedAssembly()"); Logger.Information("Managed Loader TryLoadManagedAssembly()");
try try
{ {
@ -73,7 +76,7 @@ internal partial class Loader
} }
catch (Exception ex) catch (Exception ex)
{ {
LoaderLogger.Log(ex, $"Error when loading managed assemblies. {ex.Message}"); Logger.Error(ex, "Error when loading managed assemblies. {0}", ex.Message);
throw; throw;
} }
} }
@ -86,7 +89,7 @@ internal partial class Loader
} }
catch (Exception ex) catch (Exception ex)
{ {
LoaderLogger.Log(ex, "Error while loading environment variable " + key); Logger.Error(ex, "Error while loading environment variable {0}", key);
} }
return null; return null;

View File

@ -1,225 +0,0 @@
// <copyright file="LoaderLogger.cs" company="OpenTelemetry Authors">
// Copyright The OpenTelemetry Authors
//
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
// See the License for the specific language governing permissions and
// limitations under the License.
// </copyright>
using System.Diagnostics;
using System.Text;
namespace OpenTelemetry.AutoInstrumentation.Loader;
internal static class LoaderLogger
{
private const string NixDefaultDirectory = "/var/log/opentelemetry/dotnet";
private static readonly bool DebugEnabled = IsDebugEnabled();
private static readonly string? LogDirectory = GetLogDirectory();
private static readonly string? StartupLogFilePath = SetStartupLogFilePath();
// It is not necessary to dispose of FileSink explicitly: the OS closes the respective
// native handle when the process is closed. Moreover, this is a low-volume log and
// each write operation is followed by a flush so no risk of losing some data on
// intermediary buffers due to the lack of explicit dispose.
private static readonly FileSink? LogFileSink = SetLogFileSink();
public static void Log(string message, params object[] args)
{
try
{
if (LogFileSink != null)
{
try
{
// It is possible a race with multiple threads under the same app domain.
lock (LogFileSink)
{
LogFileSink.Info($"[{DateTime.UtcNow:O}] [ThreadId: {Thread.CurrentThread.ManagedThreadId}] {message}{Environment.NewLine}", args);
}
return;
}
catch (Exception ex)
{
Console.Error.WriteLine($"Log: Exception writing to FileSink {ex}");
}
}
Console.Error.WriteLine(message, args);
}
catch (Exception ex)
{
Console.Error.WriteLine($"Log: Global exception: {ex}");
}
}
public static void Log(Exception ex, string message, params object[] args)
{
message = $"{message}{Environment.NewLine}{ex}";
Log(message, args);
}
public static void Debug(string message, params object[] args)
{
if (DebugEnabled)
{
Log(message, args);
}
}
internal static string? SetStartupLogFilePath()
{
if (LogDirectory == null)
{
return null;
}
try
{
// Pick up the parts used to build the log file name and minimize the chances
// of file name conflict with other processes.
using var process = Process.GetCurrentProcess();
// AppDomain friendly name can contain characters that are invalid in file names,
// remove any of those. For the first assembly loaded by the process this is typically
// expected to be name of the file with the application entry point.
var appDomainFriendlyName = AppDomain.CurrentDomain.FriendlyName;
var invalidChars = new string(Path.GetInvalidFileNameChars()) + new string(Path.GetInvalidPathChars());
var sb = new StringBuilder(appDomainFriendlyName);
for (int i = 0; i < sb.Length; i++)
{
if (invalidChars.IndexOf(sb[i]) != -1)
{
sb[i] = '_';
}
}
appDomainFriendlyName = sb.ToString();
// AppDomain friendly name may not be unique in the same process, use also the id.
// Per documentation the id is an integer that uniquely identifies the application
// domain within the process.
var appDomainId = AppDomain.CurrentDomain.Id;
return Path.Combine(LogDirectory, $"otel-dotnet-auto-loader-{appDomainFriendlyName}-{appDomainId}-{process?.Id}.log");
}
catch
{
// We can't get the process info
return Path.Combine(LogDirectory, $"otel-dotnet-auto-loader-{Guid.NewGuid()}.log");
}
}
private static string? GetLogDirectory()
{
string? logDirectory = null;
try
{
logDirectory = Environment.GetEnvironmentVariable("OTEL_DOTNET_AUTO_LOG_DIRECTORY");
if (logDirectory == null)
{
if (Environment.OSVersion.Platform == PlatformID.Win32NT)
{
var windowsDefaultDirectory = Path.Combine(Environment.GetFolderPath(Environment.SpecialFolder.CommonApplicationData), @"OpenTelemetry .NET AutoInstrumentation", "logs");
logDirectory = windowsDefaultDirectory;
}
else
{
// Linux
logDirectory = NixDefaultDirectory;
}
}
logDirectory = CreateDirectoryIfMissing(logDirectory) ?? Path.GetTempPath();
}
catch
{
// The try block may throw a SecurityException if not granted the System.Security.Permissions.FileIOPermission
// because of the following API calls
// - Directory.Exists
// - Environment.GetFolderPath
// - Path.GetTempPath
// Unsafe to log
logDirectory = null;
}
return logDirectory;
}
private static string? CreateDirectoryIfMissing(string pathToCreate)
{
try
{
Directory.CreateDirectory(pathToCreate);
return pathToCreate;
}
catch
{
// Unable to create the directory meaning that the user will have to create it on their own.
// It is unsafe to log here, so return null to defer deciding what the path is
return null;
}
}
private static FileSink? SetLogFileSink()
{
if (StartupLogFilePath == null)
{
return null;
}
try
{
return new FileSink(StartupLogFilePath);
}
catch (Exception ex)
{
Console.Error.WriteLine($"Log: Exception creating FileSink {ex}");
}
return null;
}
private static bool IsDebugEnabled()
{
try
{
var ddTraceDebugValue = Environment.GetEnvironmentVariable("OTEL_DOTNET_AUTO_DEBUG");
if (ddTraceDebugValue == null)
{
return false;
}
switch (ddTraceDebugValue.ToUpperInvariant())
{
case "TRUE":
case "YES":
case "Y":
case "T":
case "1":
return true;
default:
return false;
}
}
catch
{
// Default to not enabled
return false;
}
}
}

View File

@ -11,5 +11,52 @@
<!-- Hide warnings for EOL .NET Core targets (e.g. netcoreapp2.0) --> <!-- Hide warnings for EOL .NET Core targets (e.g. netcoreapp2.0) -->
<CheckEolTargetFramework>false</CheckEolTargetFramework> <CheckEolTargetFramework>false</CheckEolTargetFramework>
</PropertyGroup> </PropertyGroup>
<ItemGroup>
<Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\CustomLogger.cs">
<Link>Logging\CustomLogger.cs</Link>
</Compile>
<Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\NoopLogger.cs">
<Link>Logging\NoopLogger.cs</Link>
</Compile>
<Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\FileSink.cs">
<Link>Logging\FileSink.cs</Link>
</Compile>
<Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\RollingFileSink.cs">
<Link>Logging\RollingFileSink.cs</Link>
</Compile>
<Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\RollingInterval.cs">
<Link>Logging\RollingInterval.cs</Link>
</Compile>
<Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\PathRoller.cs">
<Link>Logging\PathRoller.cs</Link>
</Compile>
<Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\RollingLogFile.cs">
<Link>Logging\RollingLogFile.cs</Link>
</Compile>
<Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\RollingIntervalExtensions.cs">
<Link>Logging\RollingIntervalExtensions.cs</Link>
</Compile>
<Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\IOtelLogger.cs">
<Link>Logging\IOtelLogger.cs</Link>
</Compile>
<Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\ISink.cs">
<Link>Logging\ISink.cs</Link>
</Compile>
<Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\LogLevel.cs">
<Link>Logging\LogLevel.cs</Link>
</Compile>
<Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\NoopSink.cs">
<Link>Logging\NoopSink.cs</Link>
</Compile>
<Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\OtelLogging.cs">
<Link>Logging\OtelLogging.cs</Link>
</Compile>
<Compile Include="..\OpenTelemetry.AutoInstrumentation\Logging\WriteCountingStream.cs">
<Link>Logging\WriteCountingStream.cs</Link>
</Compile>
<Compile Include="..\OpenTelemetry.AutoInstrumentation\AutoInstrumentationEventSource.cs">
<Link>AutoInstrumentationEventSource.cs</Link>
</Compile>
<Compile Include="..\OpenTelemetry.AutoInstrumentation\Constants.cs" Link="Constants.cs" />
</ItemGroup>
</Project> </Project>

View File

@ -47,15 +47,9 @@ HRESULT STDMETHODCALLTYPE CorProfiler::Initialize(IUnknown* cor_profiler_info_un
{ {
auto _ = trace::Stats::Instance()->InitializeMeasure(); auto _ = trace::Stats::Instance()->InitializeMeasure();
// check if debug mode is enabled
if (IsDebugEnabled())
{
Logger::EnableDebug();
}
CorProfilerBase::Initialize(cor_profiler_info_unknown); CorProfilerBase::Initialize(cor_profiler_info_unknown);
if (IsDebugEnabled()) if (Logger::IsDebugEnabled())
{ {
const auto env_variables = GetEnvironmentVariables(env_vars_prefixes_to_display); const auto env_variables = GetEnvironmentVariables(env_vars_prefixes_to_display);
Logger::Debug("Environment variables:"); Logger::Debug("Environment variables:");
@ -76,7 +70,7 @@ HRESULT STDMETHODCALLTYPE CorProfiler::Initialize(IUnknown* cor_profiler_info_un
// code is ready to get runtime information // code is ready to get runtime information
runtime_information_ = GetRuntimeInformation(this->info_); runtime_information_ = GetRuntimeInformation(this->info_);
if (IsDebugEnabled()) if (Logger::IsDebugEnabled())
{ {
if (runtime_information_.is_desktop()) if (runtime_information_.is_desktop())
{ {
@ -2669,7 +2663,7 @@ HRESULT CorProfiler::CallTarget_RewriterCallback(RejitHandlerModule* modul
mdTypeRef wrapper_type_ref = mdTypeRefNil; mdTypeRef wrapper_type_ref = mdTypeRefNil;
GetWrapperMethodRef(module_metadata, module_id, *method_replacement, wrapper_method_ref, wrapper_type_ref); GetWrapperMethodRef(module_metadata, module_id, *method_replacement, wrapper_method_ref, wrapper_type_ref);
if (IsDebugEnabled()) if (Logger::IsDebugEnabled())
{ {
Logger::Debug("*** CallTarget_RewriterCallback() Start: ", caller->type.name, ".", caller->name, "() [IsVoid=", Logger::Debug("*** CallTarget_RewriterCallback() Start: ", caller->type.name, ".", caller->name, "() [IsVoid=",
isVoid, ", IsStatic=", isStatic, ", IntegrationType=", isVoid, ", IsStatic=", isStatic, ", IntegrationType=",
@ -2818,7 +2812,7 @@ HRESULT CorProfiler::CallTarget_RewriterCallback(RejitHandlerModule* modul
} }
// *** Emit BeginMethod call // *** Emit BeginMethod call
if (IsDebugEnabled()) if (Logger::IsDebugEnabled())
{ {
Logger::Debug("Caller Type.Id: ", HexStr(&caller->type.id, sizeof(mdToken))); Logger::Debug("Caller Type.Id: ", HexStr(&caller->type.id, sizeof(mdToken)));
Logger::Debug("Caller Type.IsGeneric: ", caller->type.isGeneric); Logger::Debug("Caller Type.IsGeneric: ", caller->type.isGeneric);

View File

@ -11,8 +11,8 @@
namespace trace { namespace trace {
namespace environment { namespace environment {
// Sets whether debug mode is enabled. Default is false. // Sets logging level used by autoinstrumentation loggers
const WSTRING debug_enabled = WStr("OTEL_DOTNET_AUTO_DEBUG"); const WSTRING log_level = WStr("OTEL_LOG_LEVEL");
// Sets the paths to integration definition JSON files. // Sets the paths to integration definition JSON files.
// Supports multiple values separated with comma, for example: // Supports multiple values separated with comma, for example:

View File

@ -56,10 +56,6 @@ bool IsNGENEnabled() {
false); false);
} }
bool IsDebugEnabled() {
CheckIfTrue(GetEnvironmentValue(environment::debug_enabled));
}
bool IsDumpILRewriteEnabled() { bool IsDumpILRewriteEnabled() {
CheckIfTrue(GetEnvironmentValue(environment::dump_il_rewrite_enabled)); CheckIfTrue(GetEnvironmentValue(environment::dump_il_rewrite_enabled));
} }

View File

@ -64,11 +64,6 @@ public:
LoggerImpl<TracerLoggerPolicy>::Instance()->Critical(args...); LoggerImpl<TracerLoggerPolicy>::Instance()->Critical(args...);
} }
static void EnableDebug()
{
LoggerImpl<TracerLoggerPolicy>::Instance()->EnableDebug();
}
static bool IsDebugEnabled() static bool IsDebugEnabled()
{ {
return LoggerImpl<TracerLoggerPolicy>::Instance()->IsDebugEnabled(); return LoggerImpl<TracerLoggerPolicy>::Instance()->IsDebugEnabled();

View File

@ -37,6 +37,12 @@ private:
LoggerImpl(); LoggerImpl();
~LoggerImpl(); ~LoggerImpl();
static inline const WSTRING log_level_none = WStr("none");
static inline const WSTRING log_level_error = WStr("error");
static inline const WSTRING log_level_warn = WStr("warn");
static inline const WSTRING log_level_info = WStr("info");
static inline const WSTRING log_level_debug = WStr("debug");
public: public:
template <typename... Args> template <typename... Args>
void Debug(const Args&... args); void Debug(const Args&... args);
@ -55,16 +61,12 @@ public:
void Flush(); void Flush();
void EnableDebug();
bool IsDebugEnabled() const; bool IsDebugEnabled() const;
static void Shutdown() static void Shutdown()
{ {
spdlog::shutdown(); spdlog::shutdown();
} }
private:
bool m_debug_logging_enabled;
}; };
template <typename TLoggerPolicy> template <typename TLoggerPolicy>
@ -90,8 +92,6 @@ std::string LoggerImpl<TLoggerPolicy>::GetLogPath(const std::string& file_name_s
template <typename TLoggerPolicy> template <typename TLoggerPolicy>
LoggerImpl<TLoggerPolicy>::LoggerImpl() LoggerImpl<TLoggerPolicy>::LoggerImpl()
{ {
m_debug_logging_enabled = false;
spdlog::set_error_handler([](const std::string& msg) { spdlog::set_error_handler([](const std::string& msg) {
// By writing into the stderr was changing the behavior in a CI scenario. // 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. // There's not a good way to report errors when trying to create the log file.
@ -99,6 +99,32 @@ LoggerImpl<TLoggerPolicy>::LoggerImpl()
// std::cerr << "LoggerImpl Handler: " << msg << std::endl; // std::cerr << "LoggerImpl Handler: " << msg << std::endl;
}); });
static auto configured_log_level = GetEnvironmentValue(environment::log_level);
if (configured_log_level == log_level_none)
{
m_fileout = spdlog::null_logger_mt("LoggerImpl");
return;
}
auto log_level = spdlog::level::info;
if (configured_log_level == log_level_error)
{
log_level = spdlog::level::err;
}
else if (configured_log_level == log_level_warn)
{
log_level = spdlog::level::warn;
}
else if (configured_log_level == log_level_info)
{
log_level = spdlog::level::info;
}
else if (configured_log_level == log_level_debug)
{
log_level = spdlog::level::debug;
}
spdlog::flush_every(std::chrono::seconds(3)); spdlog::flush_every(std::chrono::seconds(3));
static auto current_process_name = ToString(GetCurrentProcessName()); static auto current_process_name = ToString(GetCurrentProcessName());
@ -106,7 +132,8 @@ LoggerImpl<TLoggerPolicy>::LoggerImpl()
static auto current_process_without_extension = static auto current_process_without_extension =
current_process_name.substr(0, current_process_name.find_last_of(".")); current_process_name.substr(0, current_process_name.find_last_of("."));
static auto file_name_suffix = "-" + current_process_without_extension + "-" + std::to_string(current_process_id); static auto file_name_suffix =
"-" + current_process_without_extension + "-" + std::to_string(current_process_id);
try try
{ {
@ -121,10 +148,11 @@ LoggerImpl<TLoggerPolicy>::LoggerImpl()
m_fileout = spdlog::null_logger_mt("LoggerImpl"); m_fileout = spdlog::null_logger_mt("LoggerImpl");
} }
m_fileout->set_level(spdlog::level::debug); m_fileout->set_level(log_level);
m_fileout->set_pattern(TLoggerPolicy::pattern, spdlog::pattern_time_type::utc); m_fileout->set_pattern(TLoggerPolicy::pattern, spdlog::pattern_time_type::utc);
// trigger flush whenever info messages are logged
m_fileout->flush_on(spdlog::level::info); m_fileout->flush_on(spdlog::level::info);
}; };
@ -160,12 +188,9 @@ static std::string LogToString(Args const&... args)
template <typename TLoggerPolicy> template <typename TLoggerPolicy>
template <typename... Args> template <typename... Args>
void LoggerImpl<TLoggerPolicy>::Debug(const Args&... args) void LoggerImpl<TLoggerPolicy>::Debug(const Args&... args)
{
if (IsDebugEnabled())
{ {
m_fileout->debug(LogToString(args...)); m_fileout->debug(LogToString(args...));
} }
}
template <typename TLoggerPolicy> template <typename TLoggerPolicy>
template <typename... Args> template <typename... Args>
@ -201,16 +226,11 @@ void LoggerImpl<TLoggerPolicy>::Flush()
m_fileout->flush(); m_fileout->flush();
} }
template <typename TLoggerPolicy>
void LoggerImpl<TLoggerPolicy>::EnableDebug()
{
m_debug_logging_enabled = true;
}
template <typename TLoggerPolicy> template <typename TLoggerPolicy>
bool LoggerImpl<TLoggerPolicy>::IsDebugEnabled() const bool LoggerImpl<TLoggerPolicy>::IsDebugEnabled() const
{ {
return m_debug_logging_enabled; return m_fileout->level() == spdlog::level::debug;
} }
} // namespace shared } // namespace shared

View File

@ -293,7 +293,7 @@ public class EnvironmentHelper
CustomEnvironmentVariables["COR_PROFILER"] = EnvironmentTools.ProfilerClsId; CustomEnvironmentVariables["COR_PROFILER"] = EnvironmentTools.ProfilerClsId;
CustomEnvironmentVariables["COR_PROFILER_PATH"] = profilerPath; CustomEnvironmentVariables["COR_PROFILER_PATH"] = profilerPath;
CustomEnvironmentVariables["OTEL_DOTNET_AUTO_DEBUG"] = "1"; CustomEnvironmentVariables["OTEL_LOG_LEVEL"] = "debug";
CustomEnvironmentVariables["OTEL_DOTNET_AUTO_LOG_DIRECTORY"] = Path.Combine(EnvironmentTools.GetSolutionDirectory(), "build_data", "profiler-logs"); CustomEnvironmentVariables["OTEL_DOTNET_AUTO_LOG_DIRECTORY"] = Path.Combine(EnvironmentTools.GetSolutionDirectory(), "build_data", "profiler-logs");
CustomEnvironmentVariables["OTEL_DOTNET_AUTO_HOME"] = GetNukeBuildOutput(); CustomEnvironmentVariables["OTEL_DOTNET_AUTO_HOME"] = GetNukeBuildOutput();
CustomEnvironmentVariables["OTEL_DOTNET_AUTO_INTEGRATIONS_FILE"] = Environment.GetEnvironmentVariable("OTEL_DOTNET_AUTO_INTEGRATIONS_FILE") ?? GetIntegrationsPath(); CustomEnvironmentVariables["OTEL_DOTNET_AUTO_INTEGRATIONS_FILE"] = Environment.GetEnvironmentVariable("OTEL_DOTNET_AUTO_INTEGRATIONS_FILE") ?? GetIntegrationsPath();

View File

@ -49,7 +49,7 @@ public class LoaderTests
} }
#endif #endif
Environment.SetEnvironmentVariable("OTEL_DOTNET_AUTO_DEBUG", "1"); Environment.SetEnvironmentVariable("OTEL_LOG_LEVEL", "debug");
Environment.SetEnvironmentVariable("OTEL_DOTNET_AUTO_HOME", profilerDirectory); Environment.SetEnvironmentVariable("OTEL_DOTNET_AUTO_HOME", profilerDirectory);
var exception = Record.Exception(() => new AutoInstrumentation.Loader.Loader()); var exception = Record.Exception(() => new AutoInstrumentation.Loader.Loader());

View File

@ -10,7 +10,7 @@ ENV COR_ENABLE_PROFILING=1 `
OTEL_DOTNET_AUTO_HOME=C:\opentelemetry\ ` OTEL_DOTNET_AUTO_HOME=C:\opentelemetry\ `
OTEL_DOTNET_AUTO_INTEGRATIONS_FILE=C:\opentelemetry\integrations.json ` OTEL_DOTNET_AUTO_INTEGRATIONS_FILE=C:\opentelemetry\integrations.json `
OTEL_DOTNET_AUTO_TRACES_ADDITIONAL_SOURCES=TestApplication.* ` OTEL_DOTNET_AUTO_TRACES_ADDITIONAL_SOURCES=TestApplication.* `
OTEL_DOTNET_AUTO_DEBUG=1 ` OTEL_LOG_LEVEL=debug `
OTEL_DOTNET_AUTO_LOG_DIRECTORY=C:\inetpub\wwwroot\logs OTEL_DOTNET_AUTO_LOG_DIRECTORY=C:\inetpub\wwwroot\logs
WORKDIR C:\inetpub\wwwroot WORKDIR C:\inetpub\wwwroot
COPY bin/${configuration}/app.publish . COPY bin/${configuration}/app.publish .

View File

@ -23,7 +23,7 @@
"OTEL_DOTNET_AUTO_INTEGRATIONS_FILE": "$(SolutionDir)bin\\tracer-home\\integrations.json", "OTEL_DOTNET_AUTO_INTEGRATIONS_FILE": "$(SolutionDir)bin\\tracer-home\\integrations.json",
"OTEL_TRACES_EXPORTER": "zipkin", "OTEL_TRACES_EXPORTER": "zipkin",
"OTEL_EXPORTER_ZIPKIN_ENDPOINT": "http://127.0.0.1:9411/api/v2/spans", "OTEL_EXPORTER_ZIPKIN_ENDPOINT": "http://127.0.0.1:9411/api/v2/spans",
"OTEL_DOTNET_AUTO_DEBUG": "1" "OTEL_LOG_LEVEL": "debug"
}, },
"applicationUrl": "http://localhost:54568/", "applicationUrl": "http://localhost:54568/",
"nativeDebugging": true "nativeDebugging": true

View File

@ -15,7 +15,7 @@
"DOTNET_ADDITIONAL_DEPS": "$(SolutionDir)bin\\tracer-home\\AdditionalDeps", "DOTNET_ADDITIONAL_DEPS": "$(SolutionDir)bin\\tracer-home\\AdditionalDeps",
"OTEL_TRACES_EXPORTER": "zipkin", "OTEL_TRACES_EXPORTER": "zipkin",
"OTEL_EXPORTER_ZIPKIN_ENDPOINT": "http://127.0.0.1:9411/api/v2/spans", "OTEL_EXPORTER_ZIPKIN_ENDPOINT": "http://127.0.0.1:9411/api/v2/spans",
"OTEL_DOTNET_AUTO_DEBUG": "1", "OTEL_LOG_LEVEL": "debug",
"OTEL_DOTNET_AUTO_TRACES_CONSOLE_EXPORTER_ENABLED": "true", "OTEL_DOTNET_AUTO_TRACES_CONSOLE_EXPORTER_ENABLED": "true",
"OTEL_DOTNET_AUTO_INTEGRATIONS_FILE": "$(SolutionDir)bin\\tracer-home\\integrations.json", "OTEL_DOTNET_AUTO_INTEGRATIONS_FILE": "$(SolutionDir)bin\\tracer-home\\integrations.json",
"OTEL_DOTNET_AUTO_HOME": "$(SolutionDir)bin\\tracer-home\\" "OTEL_DOTNET_AUTO_HOME": "$(SolutionDir)bin\\tracer-home\\"

View File

@ -12,7 +12,7 @@
"DOTNET_ADDITIONAL_DEPS": "$(SolutionDir)bin\\tracer-home\\AdditionalDeps", "DOTNET_ADDITIONAL_DEPS": "$(SolutionDir)bin\\tracer-home\\AdditionalDeps",
"OTEL_TRACES_EXPORTER": "zipkin", "OTEL_TRACES_EXPORTER": "zipkin",
"OTEL_EXPORTER_ZIPKIN_ENDPOINT": "http://127.0.0.1:9411/api/v2/spans", "OTEL_EXPORTER_ZIPKIN_ENDPOINT": "http://127.0.0.1:9411/api/v2/spans",
"OTEL_DOTNET_AUTO_DEBUG": "1", "OTEL_LOG_LEVEL": "debug",
"OTEL_DOTNET_AUTO_TRACES_CONSOLE_EXPORTER_ENABLED": "true", "OTEL_DOTNET_AUTO_TRACES_CONSOLE_EXPORTER_ENABLED": "true",
"OTEL_DOTNET_AUTO_INTEGRATIONS_FILE": "$(SolutionDir)bin\\tracer-home\\integrations.json", "OTEL_DOTNET_AUTO_INTEGRATIONS_FILE": "$(SolutionDir)bin\\tracer-home\\integrations.json",
"OTEL_DOTNET_AUTO_TRACES_ADDITIONAL_SOURCES": "TestApplication.MongoDB", "OTEL_DOTNET_AUTO_TRACES_ADDITIONAL_SOURCES": "TestApplication.MongoDB",