Skip to content

Commit

Permalink
[log4net] bridge + trace context injection (open-telemetry#3825)
Browse files Browse the repository at this point in the history
  • Loading branch information
lachmatt authored Dec 13, 2024
1 parent 9a4cd41 commit f92f503
Show file tree
Hide file tree
Showing 38 changed files with 1,442 additions and 13 deletions.
8 changes: 5 additions & 3 deletions .cspell/company-terms.txt
Original file line number Diff line number Diff line change
@@ -1,9 +1,11 @@
appender
appenders
CNCF
opentelemetry
OTEL
OTLP
tracecontext
triager
Zipkin
parentbased
tracecontext
traceidratio
triager
Zipkin
2 changes: 2 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,8 @@ This component adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.h
- Support for .NET9.
- Support for [RabbitMQ.Client](https://www.nuget.org/packages/RabbitMQ.Client/)
traces instrumentation for versions `7.0.0`+.
- [log4net](https://www.nuget.org/packages/log4net/) [OpenTelemetry appender](https://opentelemetry.io/docs/concepts/signals/logs/#log-appender--bridge)
for versions >= `2.0.13` && < `4.0.0`
- Support for SqlClient metrics.

### Changed
Expand Down
4 changes: 2 additions & 2 deletions Directory.Packages.props
Original file line number Diff line number Diff line change
Expand Up @@ -2,9 +2,9 @@
<PropertyGroup>
<ManagePackageVersionsCentrally>true</ManagePackageVersionsCentrally>
</PropertyGroup>

<ItemGroup>
<PackageVersion Include="DotNet.ReproducibleBuilds" Version="1.2.25" />
<PackageVersion Include="log4net" Version="3.0.3" />
<PackageVersion Include="MinVer" Version="6.0.0" />
<PackageVersion Include="OpenTelemetry" Version="1.10.0" />
<PackageVersion Include="OpenTelemetry.Api" Version="1.10.0" />
Expand All @@ -13,4 +13,4 @@
<PackageVersion Include="OpenTelemetry.Instrumentation.Http" Version="1.10.0" />
<PackageVersion Include="OpenTelemetry.Instrumentation.Wcf" Version="1.10.0-beta.1" />
</ItemGroup>
</Project>
</Project>
19 changes: 19 additions & 0 deletions OpenTelemetry.AutoInstrumentation.sln
Original file line number Diff line number Diff line change
Expand Up @@ -245,6 +245,8 @@ Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "TestApplication.Owin.IIS.Ne
EndProject
Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "SdkVersionAnalyzer", "tools\SdkVersionAnalyzer\SdkVersionAnalyzer.csproj", "{C75FA076-D460-414B-97F7-6F8D0E85AE74}"
EndProject
Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "TestApplication.Log4NetBridge", "test\test-applications\integrations\TestApplication.Log4NetBridge\TestApplication.Log4NetBridge.csproj", "{926B7C03-42C2-4192-94A7-CD0B1C693279}"
EndProject
Global
GlobalSection(SolutionConfigurationPlatforms) = preSolution
Debug|Any CPU = Debug|Any CPU
Expand Down Expand Up @@ -1513,6 +1515,22 @@ Global
{C75FA076-D460-414B-97F7-6F8D0E85AE74}.Release|x64.Build.0 = Release|Any CPU
{C75FA076-D460-414B-97F7-6F8D0E85AE74}.Release|x86.ActiveCfg = Release|Any CPU
{C75FA076-D460-414B-97F7-6F8D0E85AE74}.Release|x86.Build.0 = Release|Any CPU
{926B7C03-42C2-4192-94A7-CD0B1C693279}.Debug|Any CPU.ActiveCfg = Debug|Any CPU
{926B7C03-42C2-4192-94A7-CD0B1C693279}.Debug|Any CPU.Build.0 = Debug|Any CPU
{926B7C03-42C2-4192-94A7-CD0B1C693279}.Debug|ARM64.ActiveCfg = Debug|Any CPU
{926B7C03-42C2-4192-94A7-CD0B1C693279}.Debug|ARM64.Build.0 = Debug|Any CPU
{926B7C03-42C2-4192-94A7-CD0B1C693279}.Debug|x64.ActiveCfg = Debug|Any CPU
{926B7C03-42C2-4192-94A7-CD0B1C693279}.Debug|x64.Build.0 = Debug|Any CPU
{926B7C03-42C2-4192-94A7-CD0B1C693279}.Debug|x86.ActiveCfg = Debug|Any CPU
{926B7C03-42C2-4192-94A7-CD0B1C693279}.Debug|x86.Build.0 = Debug|Any CPU
{926B7C03-42C2-4192-94A7-CD0B1C693279}.Release|Any CPU.ActiveCfg = Release|Any CPU
{926B7C03-42C2-4192-94A7-CD0B1C693279}.Release|Any CPU.Build.0 = Release|Any CPU
{926B7C03-42C2-4192-94A7-CD0B1C693279}.Release|ARM64.ActiveCfg = Release|Any CPU
{926B7C03-42C2-4192-94A7-CD0B1C693279}.Release|ARM64.Build.0 = Release|Any CPU
{926B7C03-42C2-4192-94A7-CD0B1C693279}.Release|x64.ActiveCfg = Release|Any CPU
{926B7C03-42C2-4192-94A7-CD0B1C693279}.Release|x64.Build.0 = Release|Any CPU
{926B7C03-42C2-4192-94A7-CD0B1C693279}.Release|x86.ActiveCfg = Release|Any CPU
{926B7C03-42C2-4192-94A7-CD0B1C693279}.Release|x86.Build.0 = Release|Any CPU
EndGlobalSection
GlobalSection(SolutionProperties) = preSolution
HideSolutionNode = FALSE
Expand Down Expand Up @@ -1602,6 +1620,7 @@ Global
{91D883EC-069E-46BC-B6F7-67C94299851E} = {E409ADD3-9574-465C-AB09-4324D205CC7C}
{AA3E0C5C-A4E2-46AB-BD18-2D30D3ABF692} = {E409ADD3-9574-465C-AB09-4324D205CC7C}
{C75FA076-D460-414B-97F7-6F8D0E85AE74} = {00F4C92D-6652-4BD8-A334-B35D3E711BE6}
{926B7C03-42C2-4192-94A7-CD0B1C693279} = {E409ADD3-9574-465C-AB09-4324D205CC7C}
EndGlobalSection
GlobalSection(ExtensibilityGlobals) = postSolution
SolutionGuid = {160A1D00-1F5B-40F8-A155-621B4459D78F}
Expand Down
8 changes: 8 additions & 0 deletions build/LibraryVersions.g.cs
Original file line number Diff line number Diff line change
Expand Up @@ -67,6 +67,14 @@ public static partial class LibraryVersion
new("2.67.0"),
}
},
{
"TestApplication.Log4NetBridge",
new List<PackageBuildInfo>
{
new("2.0.13"),
new("3.0.3"),
}
},
{
"TestApplication.MassTransit",
new List<PackageBuildInfo>
Expand Down
1 change: 1 addition & 0 deletions docs/config.md
Original file line number Diff line number Diff line change
Expand Up @@ -207,6 +207,7 @@ due to lack of stable semantic convention.
| ID | Instrumented library | Supported versions | Instrumentation type | Status |
|-----------|---------------------------------------------------------------------------------------------------------------------------------|--------------------|------------------------|-----------------------------------------------------------------------------------------------------------------------------------|
| `ILOGGER` | [Microsoft.Extensions.Logging](https://www.nuget.org/packages/Microsoft.Extensions.Logging) **Not supported on .NET Framework** | ≥9.0.0 | bytecode or source [1] | [Experimental](https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/versioning-and-stability.md) |
| `LOG4NET` | [log4net](https://www.nuget.org/packages/log4net) | ≥2.0.13 && < 4.0.0 | bytecode | [Experimental](https://github.com/open-telemetry/opentelemetry-specification/blob/main/specification/versioning-and-stability.md) |

**[1]**: For ASP.NET Core applications, the `LoggingBuilder` instrumentation
can be enabled without using the .NET CLR Profiler by setting
Expand Down
62 changes: 62 additions & 0 deletions docs/internal/log4net.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,62 @@
# `log4net` instrumentation

> [!IMPORTANT]
> log4net bridge and trace context injection are experimental features.
> Both instrumentations can be disabled by setting `OTEL_DOTNET_AUTO_LOGS_LOG4NET_INSTRUMENTATION_ENABLED` to `false`.
Both bridge and trace context injection are supported for `log4net` in versions >= 2.0.13 && < 4.0.0

## `log4net` [logs bridge](https://opentelemetry.io/docs/specs/otel/glossary/#log-appender--bridge)

The `log4net` logs bridge is disabled by default. In order to enable it, set `OTEL_DOTNET_AUTO_LOGS_ENABLE_LOG4NET_BRIDGE` to `true`.
When `log4net` logs bridge is enabled, and `log4net` is configured with at least 1 appender, application logs are exported in OTLP
format by default to the local instance of OpenTelemetry Collector, in addition to being written into their currently configured destination (e.g. a file).

### `log4net` logging events conversion

`log4net`'s `LoggingEvent`s are converted to OpenTelemetry log records in a following way:

- `TimeStampUtc` is set as a `Timestamp`
- `Level.Name` is set as a `SeverityText`
- If formatted strings were used for logging (e.g. by using `InfoFormat` or similar), format string is set as a `Body`
- Otherwise, `RenderedMessage` is set as a `Body`
- If formatted strings were used for logging, format arguments are added as attributes, with indexes as their names
- If formatted strings were used for logging, and `OTEL_DOTNET_AUTO_LOGS_INCLUDE_FORMATTED_MESSAGE` is set, rendered message
is added as `log4net.rendered_message` attribute
- `LoggerName` is set as an `InstrumentationScope.Name`
- `Properties`, apart from builtin properties prefixed with `log4net:`, are added as attributes
- `Exception` is used to populate the following properties: `exception.type`,`exception.message`,`exception.stacktrace`
- `Level.Value` is mapped to `SeverityNumber` as outlined in the next section

#### `log4net` level severity mapping

`log4net` levels are mapped to OpenTelemetry severity types according to the following rules based on their numerical values.

Levels with numerical values of:

- Equal to `Level.Fatal` or higher are mapped to `LogRecordSeverity.Fatal`
- Higher than or equal to `Level.Error` but lower than `Level.Fatal` are mapped to `LogRecordSeverity.Error`
- Higher than or equal to `Level.Warn` but lower than `Level.Error` are mapped to `LogRecordSeverity.Warn`
- Higher than or equal to `Level.Info` but lower than `Level.Warn` are mapped to `LogRecordSeverity.Info`
- Higher than or equal to `Level.Debug` but lower than `Level.Info` are mapped to `LogRecordSeverity.Debug`
- Lower than `Level.Debug` are mapped to `LogRecordSeverity.Trace`

## `log4net` trace context injection

Following properties are added by default to the collection of logging event's properties:

- `trace_id`
- `span_id`
- `trace_flags`

This allows for trace context to be logged into currently configured log destination, e.g. a file.
In order to use them, pattern needs to be updated.

## Known limitations of `log4net` bridge

In order for the bridge to be added, at least 1 other appender has to be configured.
Bridge should not be used when appenders are configured for both root and component loggers.
Enabling a bridge in such scenario would result in bridge being appended to both appender collections,
and logs duplication.


Original file line number Diff line number Diff line change
@@ -1,2 +1,4 @@
OpenTelemetry.AutoInstrumentation.Instrumentations.Log4Net.Bridge.Integrations.AppenderCollectionIntegration
OpenTelemetry.AutoInstrumentation.Instrumentations.Log4Net.TraceContextInjection.Integrations.AppenderAttachedImplIntegration
OpenTelemetry.AutoInstrumentation.Instrumentations.MongoDB.Integrations.MongoClientIntegrationExecute
OpenTelemetry.AutoInstrumentation.Instrumentations.MongoDB.Integrations.MongoClientIntegrationExecuteAsync
OpenTelemetry.AutoInstrumentation.Instrumentations.MongoDB.Integrations.MongoClientIntegrationExecuteAsync
Original file line number Diff line number Diff line change
@@ -1,2 +1,4 @@
OpenTelemetry.AutoInstrumentation.Instrumentations.Log4Net.Bridge.Integrations.AppenderCollectionIntegration
OpenTelemetry.AutoInstrumentation.Instrumentations.Log4Net.TraceContextInjection.Integrations.AppenderAttachedImplIntegration
OpenTelemetry.AutoInstrumentation.Instrumentations.MongoDB.Integrations.MongoClientIntegrationExecute
OpenTelemetry.AutoInstrumentation.Instrumentations.MongoDB.Integrations.MongoClientIntegrationExecuteAsync
OpenTelemetry.AutoInstrumentation.Instrumentations.MongoDB.Integrations.MongoClientIntegrationExecuteAsync
Original file line number Diff line number Diff line change
Expand Up @@ -217,6 +217,12 @@ public static class Logs
/// </summary>
public const string IncludeFormattedMessage = "OTEL_DOTNET_AUTO_LOGS_INCLUDE_FORMATTED_MESSAGE";

/// <summary>
/// Configuration key for whether or not experimental log4net bridge
/// should be enabled.
/// </summary>
public const string EnableLog4NetBridge = "OTEL_DOTNET_AUTO_LOGS_ENABLE_LOG4NET_BRIDGE";

/// <summary>
/// Configuration key for disabling all log instrumentations.
/// </summary>
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,54 @@
// Copyright The OpenTelemetry Authors
// SPDX-License-Identifier: Apache-2.0

using System.Runtime.CompilerServices;
using OpenTelemetry.AutoInstrumentation.Loading;
using OpenTelemetry.AutoInstrumentation.Plugins;
using OpenTelemetry.Logs;

namespace OpenTelemetry.AutoInstrumentation.Configurations;

internal static class EnvironmentConfigurationLogHelper
{
public static LoggerProviderBuilder UseEnvironmentVariables(
this LoggerProviderBuilder builder,
LazyInstrumentationLoader lazyInstrumentationLoader,
LogSettings settings,
PluginManager pluginManager)
{
SetExporter(builder, settings, pluginManager);
return builder;
}

private static void SetExporter(LoggerProviderBuilder builder, LogSettings settings, PluginManager pluginManager)
{
foreach (var logExporter in settings.LogExporters)
{
builder = logExporter switch
{
LogExporter.Otlp => Wrappers.AddOtlpExporter(builder, settings, pluginManager),
LogExporter.Console => Wrappers.AddConsoleExporter(builder, pluginManager),
_ => throw new ArgumentOutOfRangeException($"Log exporter '{logExporter}' is incorrect")
};
}
}

private static class Wrappers
{
[MethodImpl(MethodImplOptions.NoInlining)]
public static LoggerProviderBuilder AddConsoleExporter(LoggerProviderBuilder builder, PluginManager pluginManager)
{
return builder.AddConsoleExporter(pluginManager.ConfigureLogsOptions);
}

[MethodImpl(MethodImplOptions.NoInlining)]
public static LoggerProviderBuilder AddOtlpExporter(LoggerProviderBuilder builder, LogSettings settings, PluginManager pluginManager)
{
return builder.AddOtlpExporter(options =>
{
settings.OtlpSettings?.CopyTo(options);
pluginManager?.ConfigureLogsOptions(options);
});
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -11,5 +11,10 @@ internal enum LogInstrumentation
/// <summary>
/// ILogger instrumentation.
/// </summary>
ILogger
ILogger = 0,

/// <summary>
/// Log4Net instrumentation.
/// </summary>
Log4Net = 1,
}
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,11 @@ internal class LogSettings : Settings
/// </summary>
public bool IncludeFormattedMessage { get; private set; }

/// <summary>
/// Gets a value indicating whether the experimental log4net bridge is enabled.
/// </summary>
public bool EnableLog4NetBridge { get; private set; }

/// <summary>
/// Gets the list of enabled instrumentations.
/// </summary>
Expand All @@ -48,6 +53,7 @@ protected override void OnLoad(Configuration configuration)
}

IncludeFormattedMessage = configuration.GetBool(ConfigurationKeys.Logs.IncludeFormattedMessage) ?? false;
EnableLog4NetBridge = configuration.GetBool(ConfigurationKeys.Logs.EnableLog4NetBridge) ?? false;

var instrumentationEnabledByDefault =
configuration.GetBool(ConfigurationKeys.Logs.LogsInstrumentationEnabled) ??
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,7 @@ internal static partial class InstrumentationDefinitions
{
private static NativeCallTargetDefinition[] GetDefinitionsArray()
{
var nativeCallTargetDefinitions = new List<NativeCallTargetDefinition>(33);
var nativeCallTargetDefinitions = new List<NativeCallTargetDefinition>(35);
// Traces
var tracerSettings = Instrumentation.TracerSettings.Value;
if (tracerSettings.TracesEnabled)
Expand Down Expand Up @@ -90,6 +90,18 @@ private static NativeCallTargetDefinition[] GetDefinitionsArray()
}
}

// Logs
var logSettings = Instrumentation.LogSettings.Value;
if (logSettings.LogsEnabled)
{
// Log4Net
if (logSettings.EnabledInstrumentations.Contains(LogInstrumentation.Log4Net))
{
nativeCallTargetDefinitions.Add(new("log4net", "log4net.Appender.AppenderCollection", "ToArray", new[] {"log4net.Appender.IAppender[]"}, 2, 0, 13, 3, 65535, 65535, AssemblyFullName, "OpenTelemetry.AutoInstrumentation.Instrumentations.Log4Net.Bridge.Integrations.AppenderCollectionIntegration"));
nativeCallTargetDefinitions.Add(new("log4net", "log4net.Util.AppenderAttachedImpl", "AppendLoopOnAppenders", new[] {"System.Int32", "log4net.Core.LoggingEvent"}, 2, 0, 13, 3, 65535, 65535, AssemblyFullName, "OpenTelemetry.AutoInstrumentation.Instrumentations.Log4Net.TraceContextInjection.Integrations.AppenderAttachedImplIntegration"));
}
}

// Metrics
var metricSettings = Instrumentation.MetricSettings.Value;
if (metricSettings.MetricsEnabled)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,7 @@ internal static partial class InstrumentationDefinitions
{
private static NativeCallTargetDefinition[] GetDefinitionsArray()
{
var nativeCallTargetDefinitions = new List<NativeCallTargetDefinition>(36);
var nativeCallTargetDefinitions = new List<NativeCallTargetDefinition>(38);
// Traces
var tracerSettings = Instrumentation.TracerSettings.Value;
if (tracerSettings.TracesEnabled)
Expand Down Expand Up @@ -91,6 +91,13 @@ private static NativeCallTargetDefinition[] GetDefinitionsArray()
var logSettings = Instrumentation.LogSettings.Value;
if (logSettings.LogsEnabled)
{
// Log4Net
if (logSettings.EnabledInstrumentations.Contains(LogInstrumentation.Log4Net))
{
nativeCallTargetDefinitions.Add(new("log4net", "log4net.Appender.AppenderCollection", "ToArray", new[] {"log4net.Appender.IAppender[]"}, 2, 0, 13, 3, 65535, 65535, AssemblyFullName, "OpenTelemetry.AutoInstrumentation.Instrumentations.Log4Net.Bridge.Integrations.AppenderCollectionIntegration"));
nativeCallTargetDefinitions.Add(new("log4net", "log4net.Util.AppenderAttachedImpl", "AppendLoopOnAppenders", new[] {"System.Int32", "log4net.Core.LoggingEvent"}, 2, 0, 13, 3, 65535, 65535, AssemblyFullName, "OpenTelemetry.AutoInstrumentation.Instrumentations.Log4Net.TraceContextInjection.Integrations.AppenderAttachedImplIntegration"));
}

// ILogger
if (logSettings.EnabledInstrumentations.Contains(LogInstrumentation.ILogger))
{
Expand Down
Loading

0 comments on commit f92f503

Please sign in to comment.