diff --git a/Directory.Build.props b/Directory.Build.props index e219530..c2b84ab 100644 --- a/Directory.Build.props +++ b/Directory.Build.props @@ -18,6 +18,7 @@ true $([MSBuild]::GetDirectoryNameOfFileAbove($(MSBuildThisFileDirectory), build.bat)) $(MSBuildThisFileDirectory).artifacts + 002400000480000094000000060200000024000052534131000400000100010015b0fa59d868c7f3ea2ae67567b19e102465745f01b430a38a42b92fd41a0f5869bec1f2b33b589d78662af432fe6b789ef72d4738f7b1a86264d7aeb5185ed8995b2bb104e7c5c58845f1a618be829e410fa34a6bd7d714ece191ed68a66333a83ae7456ee32e9aeb54bc1d7410ae8c344367257e9001abb5e96ce1f1d97696 diff --git a/examples/Example.Elastic.OpenTelemetry.Worker/Program.cs b/examples/Example.Elastic.OpenTelemetry.Worker/Program.cs index 75a64d4..a9afd6a 100644 --- a/examples/Example.Elastic.OpenTelemetry.Worker/Program.cs +++ b/examples/Example.Elastic.OpenTelemetry.Worker/Program.cs @@ -4,9 +4,10 @@ using Example.Elastic.OpenTelemetry.Worker; var builder = Host.CreateApplicationBuilder(args); -builder.Services.AddHostedService(); -builder.Services.AddElasticOpenTelemetry("CustomActivitySource"); +builder.EnableElasticOpenTelemetry("CustomActivitySource"); + +builder.Services.AddHostedService(); var host = builder.Build(); host.Run(); diff --git a/examples/Example.Elastic.OpenTelemetry.Worker/appsettings.Development.json b/examples/Example.Elastic.OpenTelemetry.Worker/appsettings.Development.json index b2dcdb6..5816332 100644 --- a/examples/Example.Elastic.OpenTelemetry.Worker/appsettings.Development.json +++ b/examples/Example.Elastic.OpenTelemetry.Worker/appsettings.Development.json @@ -2,7 +2,8 @@ "Logging": { "LogLevel": { "Default": "Information", - "Microsoft.Hosting.Lifetime": "Information" + "Microsoft.Hosting.Lifetime": "Information", + "Elastic": "Trace" } } } diff --git a/src/Elastic.OpenTelemetry/Agent.cs b/src/Elastic.OpenTelemetry/Agent.cs index 2c73a33..9e22d7f 100644 --- a/src/Elastic.OpenTelemetry/Agent.cs +++ b/src/Elastic.OpenTelemetry/Agent.cs @@ -1,97 +1,145 @@ // Licensed to Elasticsearch B.V under one or more agreements. // Elasticsearch B.V licenses this file to you under the Apache 2.0 License. // See the LICENSE file in the project root for more information -using OpenTelemetry; using System.Reflection; +using Microsoft.Extensions.Logging; + +using static Elastic.OpenTelemetry.Diagnostics.ElasticOpenTelemetryDiagnosticSource; namespace Elastic.OpenTelemetry; /// /// Supports building and accessing an which collects and ships observability signals. /// -public static class Agent +public static partial class Agent { - private static readonly object Lock = new(); - private static IAgent? _current; - - static Agent() - { - var assemblyInformationalVersion = typeof(Agent).Assembly.GetCustomAttribute()?.InformationalVersion; - InformationalVersion = ParseAssemblyInformationalVersion(assemblyInformationalVersion); - } - - /// - /// Returns the singleton instance. - /// - /// - /// If an instance is not already initialized, this will create and return a - /// default configured with recommended Elastic defaults. - /// - public static IAgent Current - { - get - { - if (_current is not null) return _current; - - lock (Lock) - { - // disable to satisfy double check lock pattern analyzer - // ReSharper disable once InvertIf - if (_current is null) - { - var agent = new AgentBuilder().Build(); - _current = agent; - } - return _current; - } - } - } - - internal static string InformationalVersion { get; } - - /// - /// Builds an . - /// - /// An instance. - /// - /// An exception will be thrown if - /// is called more than once during the lifetime of an application. - /// - public static IAgent Build(Action? configuration = null) - { - if (_current != null) - throw new Exception($"{nameof(Agent)}.{nameof(Build)} called twice or after {nameof(Agent)}.{nameof(Current)} was accessed."); - - lock (Lock) - { - if (_current != null) - throw new Exception($"{nameof(Agent)}.{nameof(Build)} called twice or after {nameof(Agent)}.{nameof(Current)} was accessed."); - - var agentBuilder = new AgentBuilder(); - configuration?.Invoke(agentBuilder); - var agent = agentBuilder.Build(); - _current = agent; - return _current; - } - } - - internal static string ParseAssemblyInformationalVersion(string? informationalVersion) - { - if (string.IsNullOrWhiteSpace(informationalVersion)) - { - informationalVersion = "1.0.0"; - } - - /* - * InformationalVersion will be in the following format: - * {majorVersion}.{minorVersion}.{patchVersion}.{pre-release label}.{pre-release version}.{gitHeight}+{Git SHA of current commit} - * Ex: 1.5.0-alpha.1.40+807f703e1b4d9874a92bd86d9f2d4ebe5b5d52e4 - * The following parts are optional: pre-release label, pre-release version, git height, Git SHA of current commit - */ - - var indexOfPlusSign = informationalVersion!.IndexOf('+'); - return indexOfPlusSign > 0 - ? informationalVersion[..indexOfPlusSign] - : informationalVersion; - } + private static readonly object Lock = new(); + private static IAgent? CurrentAgent; + + static Agent() + { + var assemblyInformationalVersion = typeof(Agent).Assembly.GetCustomAttribute()?.InformationalVersion; + InformationalVersion = ParseAssemblyInformationalVersion(assemblyInformationalVersion); + } + + /// + /// Returns the singleton instance. + /// + /// + /// If an instance is not already initialized, this will create and return a + /// default configured with recommended Elastic defaults. + /// + public static IAgent Current + { + get + { + if (CurrentAgent is not null) + return CurrentAgent; + + lock (Lock) + { + // disable to satisfy double check lock pattern analyzer + // ReSharper disable once InvertIf + if (CurrentAgent is null) + { + var agent = new AgentBuilder().Build(); + CurrentAgent = agent; + } + return CurrentAgent; + } + } + } + + internal static string InformationalVersion { get; } + + /// + /// Builds an . + /// + /// An instance. + /// + /// An exception will be thrown if + /// is called more than once during the lifetime of an application. + /// + public static IAgent Build(Action? configuration = null) + { + CheckCurrent(); + + lock (Lock) + { + CheckCurrent(); + var agentBuilder = new AgentBuilder(); + configuration?.Invoke(agentBuilder); + var agent = agentBuilder.Build(); + CurrentAgent = agent; + return CurrentAgent; + } + + static void CheckCurrent() + { + if (CurrentAgent is not null) + { + Log(AgentBuildCalledMultipleTimesEvent); + throw new Exception(); + } + } + } + + internal const string BuildErrorMessage = $"{nameof(Agent)}.{nameof(Build)} called twice or after " + + $"{nameof(Agent)}.{nameof(Current)} was accessed."; + + internal const string SetAgentErrorMessage = $"{nameof(Agent)}.{nameof(SetAgent)} called twice" + + $"or after {nameof(Agent)}.{nameof(Build)} or after {nameof(Agent)}.{nameof(Current)} was accessed."; + + [LoggerMessage(EventId = 1, Level = LogLevel.Error, Message = SetAgentErrorMessage)] + internal static partial void SetAgentError(this ILogger logger); + + /// + /// TODO + /// + /// + /// + /// + /// + internal static IAgent SetAgent(IAgent agent, ILogger logger) + { + CheckCurrent(logger); + + lock (Lock) + { + CheckCurrent(logger); + logger.LogInformation($"Setting {nameof(CurrentAgent)}."); + CurrentAgent = agent; + return CurrentAgent; + } + + static void CheckCurrent(ILogger logger) + { + if (CurrentAgent is not null) + { + Log(AgentSetAgentCalledMultipleTimesEvent); + logger.SetAgentError(); + throw new Exception(SetAgentErrorMessage); + } + } + } + + internal static string ParseAssemblyInformationalVersion(string? informationalVersion) + { + if (string.IsNullOrWhiteSpace(informationalVersion)) + { + informationalVersion = "1.0.0"; + } + + /* + * InformationalVersion will be in the following format: + * {majorVersion}.{minorVersion}.{patchVersion}.{pre-release label}.{pre-release version}.{gitHeight}+{Git SHA of current commit} + * Ex: 1.5.0-alpha.1.40+807f703e1b4d9874a92bd86d9f2d4ebe5b5d52e4 + * The following parts are optional: pre-release label, pre-release version, git height, Git SHA of current commit + */ + + var indexOfPlusSign = informationalVersion!.IndexOf('+'); + return indexOfPlusSign > 0 + ? informationalVersion[..indexOfPlusSign] + : informationalVersion; + } } diff --git a/src/Elastic.OpenTelemetry/AgentBuilder.cs b/src/Elastic.OpenTelemetry/AgentBuilder.cs index 479addd..9c52517 100644 --- a/src/Elastic.OpenTelemetry/AgentBuilder.cs +++ b/src/Elastic.OpenTelemetry/AgentBuilder.cs @@ -2,25 +2,21 @@ // Elasticsearch B.V licenses this file to you under the Apache 2.0 License. // See the LICENSE file in the project root for more information using System.Diagnostics; +using Elastic.OpenTelemetry.DependencyInjection; +using Elastic.OpenTelemetry.Diagnostics; using Elastic.OpenTelemetry.Extensions; using Elastic.OpenTelemetry.Resources; using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Logging; using OpenTelemetry; using OpenTelemetry.Exporter; using OpenTelemetry.Metrics; using OpenTelemetry.Resources; using OpenTelemetry.Trace; -namespace Elastic.OpenTelemetry; +using static Elastic.OpenTelemetry.Diagnostics.ElasticOpenTelemetryDiagnosticSource; -/// -/// -/// -public class DebugExporter : BaseExporter -{ - /// - public override ExportResult Export(in Batch batch) => ExportResult.Success; -} +namespace Elastic.OpenTelemetry; /// /// Supports building instances which include Elastic defaults, but can also be customised. @@ -42,7 +38,7 @@ public class AgentBuilder .AddRuntimeInstrumentation() .AddHttpClientInstrumentation(); - private readonly string[]? _activitySourceNames; + private readonly string[] _activitySourceNames = []; private Action _tracerProviderBuilderAction = tpb => { }; private Action? _resourceBuilderAction; private Action? _otlpExporterConfiguration; @@ -51,13 +47,26 @@ public class AgentBuilder /// /// TODO /// - public AgentBuilder() { } + public AgentBuilder() + { + if (LogFileWriter.FileLoggingEnabled) + { + // Enables logging of OpenTelemetry-SDK event source events + _ = new LoggingEventListener(LogFileWriter.Instance); + + // Enables logging of Elastic OpenTelemetry diagnostic source events + var listener = new LoggingDiagnosticSourceListener(LogFileWriter.Instance); + DiagnosticListener.AllListeners.Subscribe(listener); + } + + Log(AgentBuilderInitializedEvent, () => new DiagnosticEvent(new StackTrace(true))); + } // NOTE - Applies to all signals /// /// TODO /// - public AgentBuilder(params string[] activitySourceNames) => _activitySourceNames = activitySourceNames; + public AgentBuilder(params string[] activitySourceNames) : this() => _activitySourceNames = activitySourceNames; // NOTE: The builder methods below are extremely experimental and will go through a final API design and // refinement before alpha 1 @@ -181,7 +190,14 @@ public IAgent Build() var tracerProviderBuilder = Sdk.CreateTracerProviderBuilder(); TracerProviderBuilderAction.Invoke(tracerProviderBuilder); var tracerProvider = tracerProviderBuilder.Build(); - return tracerProvider is not null ? new Agent(tracerProvider) : new Agent(); + + Log(AgentBuilderBuiltTracerProviderEvent); + + var agent = tracerProvider is not null ? new Agent(tracerProvider) : new Agent(); + + Log(AgentBuilderBuiltAgentEvent); + + return agent; } /// @@ -191,24 +207,38 @@ public IAgent Build() /// The supplied . public IServiceCollection Register(IServiceCollection serviceCollection) { + // TODO - Docs, we should explain that prior to .NET 8, this needs to be added first if other hosted services emit signals. + // On .NET 8 we handle this with IHostedLifecycleService + _ = serviceCollection + .AddHostedService() + .AddSingleton() + .AddSingleton() .AddOpenTelemetry() .WithTracing(TracerProviderBuilderAction); + Log(AgentBuilderRegisteredDistroServicesEvent); + return serviceCollection; } private Action TracerProviderBuilderAction => tracerProviderBuilder => { - if (_activitySourceNames is not null) - tracerProviderBuilder.AddSource(_activitySourceNames); + foreach (var source in _activitySourceNames) + tracerProviderBuilder.LogAndAddSource(source); tracerProviderBuilder .AddHttpClientInstrumentation() .AddGrpcClientInstrumentation() - .AddEntityFrameworkCoreInstrumentation() - .AddElasticProcessors(); + .AddEntityFrameworkCoreInstrumentation(); // TODO - Should we add this by default? + + // TODO - Update these to capture the builder type also + //Log.AddedInstrumentation("HttpClient"); + //Log.AddedInstrumentation("GrpcClient"); + //Log.AddedInstrumentation("EntityFrameworkCore"); + + tracerProviderBuilder.AddElasticProcessors(); if (_resourceBuilderAction is not null) { @@ -221,15 +251,10 @@ public IServiceCollection Register(IServiceCollection serviceCollection) tracerProviderBuilder.ConfigureResource(DefaultResourceBuilderConfiguration); } + // TODO - Can/should we use reflection to determine and log what is configured by the user action? _tracerProviderBuilderAction?.Invoke(tracerProviderBuilder); - // Add the OTLP exporter configured to ship data to an Elastic backend. - // TODO - What about cases where users want to register processors/exporters after any exporters we add by default (OTLP)? tracerProviderBuilder.AddElasticOtlpExporter(_otlpExporterConfiguration, _otlpExporterName); - -#if DEBUG - tracerProviderBuilder.AddProcessor(new SimpleActivityExportProcessor(new DebugExporter())); -#endif }; /// @@ -242,14 +267,12 @@ public void ConfigureOtlpExporter(Action configure, string? _otlpExporterName = name; } - private sealed class Agent(TracerProvider? tracerProvider, MeterProvider? meterProvider) : IAgent + private class Agent(TracerProvider? tracerProvider, MeterProvider? meterProvider) : IAgent { - private bool _disposedValue; - private readonly TracerProvider? _tracerProvider = tracerProvider; private readonly MeterProvider? _meterProvider = meterProvider; - internal Agent() : this(null, null) + public Agent() : this(null, null) { } @@ -257,24 +280,18 @@ internal Agent(TracerProvider tracerProvider) : this(tracerProvider, null) { } - private void Dispose(bool disposing) + public void Dispose() { - if (!_disposedValue) - { - if (disposing) - { - _tracerProvider?.Dispose(); - _meterProvider?.Dispose(); - } - - _disposedValue = true; - } + _tracerProvider?.Dispose(); + _meterProvider?.Dispose(); + LogFileWriter.Instance.Dispose(); } - public void Dispose() + public async ValueTask DisposeAsync() { - Dispose(disposing: true); - GC.SuppressFinalize(this); + _tracerProvider?.Dispose(); + _meterProvider?.Dispose(); + await LogFileWriter.Instance.DisposeAsync().ConfigureAwait(false); } } } diff --git a/src/Elastic.OpenTelemetry/DependencyInjection/ElasticOtelDistroService.cs b/src/Elastic.OpenTelemetry/DependencyInjection/ElasticOtelDistroService.cs new file mode 100644 index 0000000..27e7aeb --- /dev/null +++ b/src/Elastic.OpenTelemetry/DependencyInjection/ElasticOtelDistroService.cs @@ -0,0 +1,36 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information +using Elastic.OpenTelemetry.DependencyInjection; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Hosting; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Logging.Abstractions; + +namespace Elastic.OpenTelemetry +{ + internal sealed class ElasticOtelDistroService(IServiceProvider serviceProvider) : IHostedService, IHostedLifecycleService + { + private readonly IServiceProvider _serviceProvider = serviceProvider; + + public Task StartingAsync(CancellationToken cancellationToken) + { + var agent = _serviceProvider.GetRequiredService(); + var loggerFactory = _serviceProvider.GetService(); + var logger = loggerFactory?.CreateLogger($"{nameof(Elastic)}.{nameof(OpenTelemetry)}") ?? NullLogger.Instance; + + _serviceProvider.GetService(); + + logger.LogInformation("Initialising Agent.Current."); + Agent.SetAgent(agent, logger); + + return Task.CompletedTask; + } + + public Task StartAsync(CancellationToken cancellationToken) => Task.CompletedTask; + public Task StartedAsync(CancellationToken cancellationToken) => Task.CompletedTask; + public Task StoppingAsync(CancellationToken cancellationToken) => Task.CompletedTask; + public Task StopAsync(CancellationToken cancellationToken) => Task.CompletedTask; + public Task StoppedAsync(CancellationToken cancellationToken) => Task.CompletedTask; + } +} diff --git a/src/Elastic.OpenTelemetry/DependencyInjection/LoggerResolver.cs b/src/Elastic.OpenTelemetry/DependencyInjection/LoggerResolver.cs new file mode 100644 index 0000000..04b7c70 --- /dev/null +++ b/src/Elastic.OpenTelemetry/DependencyInjection/LoggerResolver.cs @@ -0,0 +1,26 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Logging.Abstractions; + +namespace Elastic.OpenTelemetry.DependencyInjection; + +internal sealed class LoggerResolver +{ + private static ILoggerFactory LoggerFactory = NullLoggerFactory.Instance; + + public LoggerResolver(ILoggerFactory loggerFactory) + { + if (LoggerFactory == NullLoggerFactory.Instance) + LoggerFactory = loggerFactory; + } + + internal static ILogger GetLogger() => LoggerFactory.CreateLogger(); + + internal static ILogger GetLogger(ref ILogger? logger) + { + logger = LoggerFactory.CreateLogger(); + return logger; + } +} diff --git a/src/Elastic.OpenTelemetry/DependencyInjection/ServiceCollectionExtensions.cs b/src/Elastic.OpenTelemetry/DependencyInjection/ServiceCollectionExtensions.cs index 6329005..28153ee 100644 --- a/src/Elastic.OpenTelemetry/DependencyInjection/ServiceCollectionExtensions.cs +++ b/src/Elastic.OpenTelemetry/DependencyInjection/ServiceCollectionExtensions.cs @@ -2,6 +2,7 @@ // Elasticsearch B.V licenses this file to you under the Apache 2.0 License. // See the LICENSE file in the project root for more information using Elastic.OpenTelemetry; +using Microsoft.Extensions.Hosting; using OpenTelemetry.Trace; namespace Microsoft.Extensions.DependencyInjection; @@ -11,6 +12,26 @@ namespace Microsoft.Extensions.DependencyInjection; /// public static class ServiceCollectionExtensions { + /// + /// TODO + /// + /// + /// + public static IHostApplicationBuilder EnableElasticOpenTelemetry(this IHostApplicationBuilder builder) => + EnableElasticOpenTelemetry(builder, []); + + /// + /// TODO + /// + /// + /// + /// + public static IHostApplicationBuilder EnableElasticOpenTelemetry(this IHostApplicationBuilder builder, params string[] activitySourceNames) + { + builder.Services.AddElasticOpenTelemetry(activitySourceNames); + return builder; + } + /// /// Adds the Elastic OpenTelemetry distribution to an application via the . /// diff --git a/src/Elastic.OpenTelemetry/Diagnostics/DiagnosticErrorLevels.cs b/src/Elastic.OpenTelemetry/Diagnostics/DiagnosticErrorLevels.cs new file mode 100644 index 0000000..daf96e7 --- /dev/null +++ b/src/Elastic.OpenTelemetry/Diagnostics/DiagnosticErrorLevels.cs @@ -0,0 +1,36 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information +namespace Elastic.OpenTelemetry.Diagnostics; + +internal static class DiagnosticErrorLevels +{ + public const string Critical = "Critical"; + public const string Error = "Error"; + public const string Warning = "Warn"; + public const string Info = "Info"; + public const string Trace = "Trace"; + + public static LogLevel ToLogLevel(string logLevelString) => + logLevelString switch + { + Critical => LogLevel.Critical, + Error => LogLevel.Error, + Warning => LogLevel.Warning, + Info => LogLevel.Info, + Trace => LogLevel.Trace, + _ => LogLevel.Unknown, + }; + + public static string AsString(this LogLevel logLevel) => + logLevel switch + { + LogLevel.Critical => Critical, + LogLevel.Error => Error, + LogLevel.Warning => Warning, + LogLevel.Info => Info, + LogLevel.Trace => Trace, + LogLevel.Unknown => string.Empty, + _ => string.Empty + }; +} diff --git a/src/Elastic.OpenTelemetry/Diagnostics/DiagnosticEvent.cs b/src/Elastic.OpenTelemetry/Diagnostics/DiagnosticEvent.cs new file mode 100644 index 0000000..0452284 --- /dev/null +++ b/src/Elastic.OpenTelemetry/Diagnostics/DiagnosticEvent.cs @@ -0,0 +1,29 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information +using System.Diagnostics; +using Elastic.OpenTelemetry.DependencyInjection; +using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Logging.Abstractions; + +namespace Elastic.OpenTelemetry.Diagnostics; + +internal class DiagnosticEvent(Activity? activity = null, ILogger? logger = null) +{ + public int ManagedThreadId { get; } = Environment.CurrentManagedThreadId; + + public DateTime DateTime { get; } = DateTime.UtcNow; + + public Activity? Activity { get; } = activity ?? Activity.Current; + + public ILogger Logger { get; } = logger ?? NullLogger.Instance; + + public static DiagnosticEvent Create(ref ILogger? logger, Activity? activity = null) => + new(activity, logger ?? LoggerResolver.GetLogger(ref logger)); +} + +internal class DiagnosticEvent(T data, Activity? activity = null, ILogger? logger = null) : DiagnosticEvent(activity, logger) +{ + public T Data { get; init; } = data; +} + diff --git a/src/Elastic.OpenTelemetry/Diagnostics/ElasticDiagnosticLoggingObserver.cs b/src/Elastic.OpenTelemetry/Diagnostics/ElasticDiagnosticLoggingObserver.cs new file mode 100644 index 0000000..e80ae91 --- /dev/null +++ b/src/Elastic.OpenTelemetry/Diagnostics/ElasticDiagnosticLoggingObserver.cs @@ -0,0 +1,121 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information +using System.Diagnostics; +using Elastic.OpenTelemetry.Extensions; + +namespace Elastic.OpenTelemetry.Diagnostics; + +internal sealed class ElasticDiagnosticLoggingObserver(LogFileWriter logFileWriter) : IObserver> +{ + private readonly LogFileWriter _logFileWriter = logFileWriter; + + public void OnNext(KeyValuePair data) + { + if (data.Value is not DiagnosticEvent) + return; + + switch (data.Key) + { + case ElasticOpenTelemetryDiagnosticSource.AgentBuilderInitializedEvent: + AgentBuilderInitialized(data); + break; + + case ElasticOpenTelemetryDiagnosticSource.AgentBuilderBuiltTracerProviderEvent: + AgentBuilderBuiltTracerProvider(data); + break; + + case ElasticOpenTelemetryDiagnosticSource.AgentBuilderBuiltAgentEvent: + AgentBuilderBuiltAgent(data); + break; + + case ElasticOpenTelemetryDiagnosticSource.AgentBuildCalledMultipleTimesEvent: + AgentBuilderBuildCalledMultipleTimes(data); + break; + + case ElasticOpenTelemetryDiagnosticSource.AgentSetAgentCalledMultipleTimesEvent: + AgentBuilderSetAgentCalledMultipleTimes(data); + break; + + case ElasticOpenTelemetryDiagnosticSource.AgentBuilderRegisteredDistroServicesEvent: + AgentBuilderRegisteredDistroServices(data); + break; + + case ElasticOpenTelemetryDiagnosticSource.TransactionIdAddedEvent: + TransactionIdAdded(data); + break; + + case ElasticOpenTelemetryDiagnosticSource.ProcessorAddedEvent: + ProcessorAdded(data); + break; + + case ElasticOpenTelemetryDiagnosticSource.SourceAddedEvent: + SourceAdded(data); + break; + + default: + if (data.Value is DiagnosticEvent diagnostic) + _logFileWriter.LogUnhandledEvent(data.Key, diagnostic); + break; + } + + void AgentBuilderInitialized(KeyValuePair data) + { + if (data.Value is DiagnosticEvent diagnostic) + _logFileWriter.LogAgentBuilderInitialized(diagnostic); + } + + void AgentBuilderBuiltTracerProvider(KeyValuePair data) + { + if (data.Value is DiagnosticEvent diagnostic) + _logFileWriter.LogAgentBuilderBuiltTracerProvider(diagnostic); + } + + void AgentBuilderBuiltAgent(KeyValuePair data) + { + if (data.Value is DiagnosticEvent diagnostic) + _logFileWriter.LogAgentBuilderBuiltAgent(diagnostic); + } + + void AgentBuilderRegisteredDistroServices(KeyValuePair data) + { + if (data.Value is DiagnosticEvent diagnostic) + _logFileWriter.LogAgentBuilderRegisteredServices(diagnostic); + } + + void AgentBuilderBuildCalledMultipleTimes(KeyValuePair data) + { + if (data.Value is DiagnosticEvent diagnostic) + _logFileWriter.LogAgentBuilderBuildCalledMultipleTimes(diagnostic); + } + + void AgentBuilderSetAgentCalledMultipleTimes(KeyValuePair data) + { + if (data.Value is DiagnosticEvent diagnostic) + _logFileWriter.LogAgentBuilderSetAgentCalledMultipleTimes(diagnostic); + } + + void TransactionIdAdded(KeyValuePair data) + { + if (data.Value is DiagnosticEvent diagnostic) + _logFileWriter.LogAddedTransactionIdTag(diagnostic); + } + + void ProcessorAdded(KeyValuePair data) + { + if (data.Value is DiagnosticEvent diagnostic) + _logFileWriter.LogProcessorAdded(diagnostic); + } + + void SourceAdded(KeyValuePair data) + { + if (data.Value is DiagnosticEvent diagnostic) + _logFileWriter.LogSourceAdded(diagnostic); + } + } + + public void OnCompleted() { } + + public void OnError(Exception error) { } +} + diff --git a/src/Elastic.OpenTelemetry/Diagnostics/ElasticOpenTelemetryDiagnosticSource.cs b/src/Elastic.OpenTelemetry/Diagnostics/ElasticOpenTelemetryDiagnosticSource.cs new file mode 100644 index 0000000..b609b13 --- /dev/null +++ b/src/Elastic.OpenTelemetry/Diagnostics/ElasticOpenTelemetryDiagnosticSource.cs @@ -0,0 +1,108 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information +using System.Diagnostics; +using Elastic.OpenTelemetry.DependencyInjection; +using Elastic.OpenTelemetry.Extensions; +using Microsoft.Extensions.Logging.Abstractions; + +namespace Elastic.OpenTelemetry.Diagnostics; + +internal static class ElasticOpenTelemetryDiagnosticSource +{ + public const string DiagnosticSourceName = "Elastic.OpenTelemetry"; + + internal static readonly DiagnosticSource DiagnosticSource = new DiagnosticListener(DiagnosticSourceName); + + public static void Log(string name) + { + if (DiagnosticSource.IsEnabled(name)) + DiagnosticSource.Write(name, new DiagnosticEvent()); + } + + public static void Log(string name, Func createDiagnosticEvent) + { + // We take a func here so that we only create an instance of the DiagnosticEvent when + // there is a listener for the event. + + if (DiagnosticSource.IsEnabled(name) && createDiagnosticEvent is not null) + DiagnosticSource.Write(name, createDiagnosticEvent.Invoke()); + } + + // Events + + public const string AgentBuilderInitializedEvent = "AgentBuilderInitialized"; + + public const string AgentBuilderBuiltTracerProviderEvent = "AgentBuilderBuiltTracerProvider"; + + public const string AgentBuilderRegisteredDistroServicesEvent = "RegisteredDistroServices"; + + public const string AgentBuilderBuiltAgentEvent = "AgentBuilderBuiltAgent"; + + public const string TransactionIdAddedEvent = "TransactionIdAdded"; + + public const string ProcessorAddedEvent = "ProcessorAdded"; + + public const string SourceAddedEvent = "SourceAdded"; + + public const string AgentBuildCalledMultipleTimesEvent = "AgentBuildCalledMultipleTimes"; + + public const string AgentSetAgentCalledMultipleTimesEvent = "AgentSetAgentCalledMultipleTimes"; + + public static void LogAgentBuilderInitialized(this LogFileWriter logFileWriter, DiagnosticEvent diagnostic) + { + var message = diagnostic.Data is not null + ? $"AgentBuilder initialized{Environment.NewLine}{diagnostic.Data}." + : "AgentBuilder initialized."; + + logFileWriter.WriteInfoLogLine(diagnostic, message); + } + + public static void LogAgentBuilderBuiltTracerProvider(this LogFileWriter logFileWriter, DiagnosticEvent diagnostic) => + logFileWriter.WriteInfoLogLine(diagnostic, "AgentBuilder built TracerProvider."); + + public static void LogAgentBuilderBuiltAgent(this LogFileWriter logFileWriter, DiagnosticEvent diagnostic) => + logFileWriter.WriteInfoLogLine(diagnostic, "AgentBuilder built Agent."); + + public static void LogAgentBuilderRegisteredServices(this LogFileWriter logFileWriter, DiagnosticEvent diagnostic) => + logFileWriter.WriteInfoLogLine(diagnostic, "AgentBuilder registered agent services into IServiceCollection."); + + public static void LogAgentBuilderBuildCalledMultipleTimes(this LogFileWriter logFileWriter, DiagnosticEvent diagnostic) => + logFileWriter.WriteErrorLogLine(diagnostic, Agent.BuildErrorMessage); + + public static void LogAgentBuilderSetAgentCalledMultipleTimes(this LogFileWriter logFileWriter, DiagnosticEvent diagnostic) => + logFileWriter.WriteErrorLogLine(diagnostic, Agent.SetAgentErrorMessage); + + public static void LogAddedTransactionIdTag(this LogFileWriter logFileWriter, DiagnosticEvent diagnostic) + { + diagnostic.Logger.TransactionIdProcessorTagAdded(); + logFileWriter.WriteTraceLogLine(diagnostic, LoggerMessages.TransactionIdProcessorTagAddedLog); + } + + public static void LogProcessorAdded(this LogFileWriter logFileWriter, DiagnosticEvent diagnostic) + { + var message = $"Added '{diagnostic.Data.ProcessorType}' processor to '{diagnostic.Data.BuilderType.Name}'."; + logFileWriter.WriteInfoLogLine(diagnostic, message); + } + + public static void LogSourceAdded(this LogFileWriter logFileWriter, DiagnosticEvent diagnostic) + { + var message = $"Added '{diagnostic.Data.ActivitySourceName}' ActivitySource to '{diagnostic.Data.BuilderType.Name}'."; + logFileWriter.WriteInfoLogLine(diagnostic, message); + } + + public static void LogUnhandledEvent(this LogFileWriter logFileWriter, string eventKey, DiagnosticEvent diagnostic) + { + // Prefer the logger from the source of the event, when present, otherwise + // fallback to using a logger typed to the ElasticDiagnosticLoggingObserver instead. + + var logger = diagnostic.Logger; + + if (logger == NullLogger.Instance) + logger = LoggerResolver.GetLogger(); + + logger.UnhandledDiagnosticEvent(eventKey); + + logFileWriter.WriteWarningLogLine(diagnostic, $"Received an unhandled diagnostic event '{eventKey}'."); + } +} diff --git a/src/Elastic.OpenTelemetry/Diagnostics/LogFileWriter.cs b/src/Elastic.OpenTelemetry/Diagnostics/LogFileWriter.cs new file mode 100644 index 0000000..4e4cc66 --- /dev/null +++ b/src/Elastic.OpenTelemetry/Diagnostics/LogFileWriter.cs @@ -0,0 +1,311 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information +using System.Diagnostics; +using System.Runtime.InteropServices; +using System.Text; +using System.Threading.Channels; +using System.Xml.Serialization; + +namespace Elastic.OpenTelemetry.Diagnostics; + +internal sealed class LogFileWriter : IDisposable, IAsyncDisposable +{ + public static readonly bool FileLoggingEnabled = IsFileLoggingEnabled(); + + private readonly StreamWriter _streamWriter; + private readonly Channel _channel = Channel.CreateBounded(new BoundedChannelOptions(1024) + { + SingleReader = true, + SingleWriter = false, + AllowSynchronousContinuations = true, + FullMode = BoundedChannelFullMode.Wait + }); + + private LogFileWriter() + { + var process = Process.GetCurrentProcess(); + + var configuredPath = Environment.GetEnvironmentVariable(EnvironmentVariables.ElasticOtelLogDirectoryEnvironmentVariable); + + // Defaults to local application data (C:\Users\{username}\AppData\Local\Elastic on Windows; $HOME/.local/share/elastic on Linux) + var path = string.IsNullOrEmpty(configuredPath) + ? Path.Combine(Environment.GetFolderPath(Environment.SpecialFolder.LocalApplicationData), GetElasticFolder) + : configuredPath; + + // When ordered by filename, we get see logs from the same process grouped, then ordered by oldest to newest, then the PID for that instance + LogFilePath = Path.Combine(path, $"{process.ProcessName}_{DateTimeOffset.UtcNow.ToUnixTimeMilliseconds()}_{process.Id}.agent.log"); + + if (!Directory.Exists(path)) + Directory.CreateDirectory(path); + + _streamWriter = new StreamWriter(LogFilePath, Encoding.UTF8, new FileStreamOptions + { + Access = FileAccess.Write, + Mode = FileMode.OpenOrCreate, + }); + + WritingTask = Task.Run(async () => + { + while (await _channel.Reader.WaitToReadAsync().ConfigureAwait(false)) + { + while (_channel.Reader.TryRead(out var logLine)) + { + await _streamWriter.WriteLineAsync(logLine).ConfigureAwait(false); + } + } + }); + + var builder = StringBuilderCache.Acquire(); + + // Preamble and configuration entries are ALWAYS logged, regardless of the configured log level + LogPreamble(process, builder, _streamWriter); + LogConfiguration(builder, _streamWriter); + + StringBuilderCache.Release(builder); + + _streamWriter.AutoFlush = true; // Ensure we don't lose logs by not flushing to the file. + + static void LogPreamble(Process process, StringBuilder stringBuilder, StreamWriter streamWriter) + { + string[] preAmble = [ + $"Elastic OpenTelemetry Distribution: {Agent.InformationalVersion}", + $"Process ID: {process.Id}", + $"Process name: {process.ProcessName}", + $"Process path: {Environment.ProcessPath}", + $"Process started: {process.StartTime.ToUniversalTime():yyyy-MM-dd HH:mm:ss.fff}", + $"Machine name: {Environment.MachineName}", + $"Process username: {Environment.UserName}", + $"User domain name: {Environment.UserDomainName}", + $"Command line: {Environment.CommandLine}", + $"Command current directory: {Environment.CurrentDirectory}", + $"Processor count: {Environment.ProcessorCount}", + $"OS version: {Environment.OSVersion}", + $"CLR version: {Environment.Version}", + ]; + + foreach (var item in preAmble) + { + WriteLogPrefix(LogLevel.Info, stringBuilder); + stringBuilder.Append(item); + streamWriter.WriteLine(stringBuilder.ToString()); + stringBuilder.Clear(); + } + + streamWriter.Flush(); + } + + static void LogConfiguration(StringBuilder stringBuilder, StreamWriter streamWriter) + { + string[] environmentVariables = [ + EnvironmentVariables.ElasticOtelFileLogging, + EnvironmentVariables.ElasticOtelLogDirectoryEnvironmentVariable, + EnvironmentVariables.ElasticOtelLogLevelEnvironmentVariable + ]; + + foreach (var variable in environmentVariables) + { + var envVarValue = Environment.GetEnvironmentVariable(variable); + + WriteLogPrefix(LogLevel.Info, stringBuilder); + + if (!string.IsNullOrEmpty(envVarValue)) + { + stringBuilder.Append($"Environment variable '{variable}' = '{envVarValue}'."); + streamWriter.WriteLine(stringBuilder.ToString()); + } + else + { + stringBuilder.Append($"Environment variable '{variable}' is not configured."); + streamWriter.WriteLine(stringBuilder.ToString()); + } + + stringBuilder.Clear(); + } + + streamWriter.Flush(); + } + } + + private static readonly LogLevel ConfiguredLogLevel = GetConfiguredLogLevel(); + + public static LogLevel GetConfiguredLogLevel() + { + var logLevel = LogLevel.Info; + + var logLevelEnvironmentVariable = Environment.GetEnvironmentVariable(EnvironmentVariables.ElasticOtelLogLevelEnvironmentVariable); + + if (!string.IsNullOrEmpty(logLevelEnvironmentVariable)) + { + if (logLevelEnvironmentVariable.Equals(DiagnosticErrorLevels.Trace, StringComparison.OrdinalIgnoreCase)) + logLevel = LogLevel.Trace; + + else if (logLevelEnvironmentVariable.Equals(DiagnosticErrorLevels.Info, StringComparison.OrdinalIgnoreCase)) + logLevel = LogLevel.Info; + + else if (logLevelEnvironmentVariable.Equals(DiagnosticErrorLevels.Warning, StringComparison.OrdinalIgnoreCase)) + logLevel = LogLevel.Warning; + + else if (logLevelEnvironmentVariable.Equals(DiagnosticErrorLevels.Error, StringComparison.OrdinalIgnoreCase)) + logLevel = LogLevel.Error; + + else if (logLevelEnvironmentVariable.Equals(DiagnosticErrorLevels.Critical, StringComparison.OrdinalIgnoreCase)) + logLevel = LogLevel.Critical; + } + + return logLevel; + } + + private static void WriteLogPrefix(LogLevel logLevel, StringBuilder builder) => + WriteLogPrefix(Environment.CurrentManagedThreadId, DateTime.UtcNow, logLevel, builder); + + private const string EmptySpanId = "------"; + + private static void WriteLogPrefix(int managedThreadId, DateTime dateTime, LogLevel level, StringBuilder builder, string spanId = "") + { + const int maxLength = 5; + + if (string.IsNullOrEmpty(spanId)) + spanId = EmptySpanId; + + var threadId = new string('-', maxLength); + + if (managedThreadId > 0) + { + var digits = (int)Math.Floor(Math.Log10(managedThreadId) + 1); + + if (digits < 5) + { + Span buffer = stackalloc char[maxLength]; + for (var i = 0; i < maxLength - digits; i++) + { + buffer[i] = '0'; + } + managedThreadId.TryFormat(buffer[(maxLength - digits)..], out _); + threadId = buffer.ToString(); + } + else + { + threadId = managedThreadId.ToString(); + } + } + + builder.Append('[') + .Append(dateTime.ToString("yyyy-MM-dd HH:mm:ss.fff")) + .Append("][") + .Append(threadId) + .Append("][") + .Append(spanId[..6]) + .Append("][") + .Append(level.AsString()) + .Append(']'); + + var length = builder.Length; + var padding = 52 - length; + + for (var i = 0; i < padding; i++) + { + builder.Append(' '); + } + } + + public static LogFileWriter Instance { get; } = new(); + + public string LogFilePath { get; } + + public Task WritingTask { get; } + + public void WriteCriticalLogLine(DiagnosticEvent diagnosticEvent, string message) => + WriteLogLine(diagnosticEvent, LogLevel.Critical, message); + + public void WriteErrorLogLine(DiagnosticEvent diagnosticEvent, string message) => + WriteLogLine(diagnosticEvent, LogLevel.Error, message); + + public void WriteWarningLogLine(DiagnosticEvent diagnosticEvent, string message) => + WriteLogLine(diagnosticEvent, LogLevel.Warning, message); + + public void WriteInfoLogLine(DiagnosticEvent diagnosticEvent, string message) => + WriteLogLine(diagnosticEvent, LogLevel.Info, message); + + public void WriteTraceLogLine(DiagnosticEvent diagnosticEvent, string message) => + WriteLogLine(diagnosticEvent, LogLevel.Trace, message); + + public void WriteLogLine(DiagnosticEvent diagnosticEvent, LogLevel logLevel, string message) => + WriteLogLine(diagnosticEvent.Activity, diagnosticEvent.ManagedThreadId, diagnosticEvent.DateTime, logLevel, message); + + public void WriteLogLine(Activity? activity, int managedThreadId, DateTime dateTime, LogLevel logLevel, string logLine) => + WriteLogLine(activity, managedThreadId, dateTime, logLevel, logLine, null); + + public void WriteLogLine(Activity? activity, int managedThreadId, DateTime dateTime, LogLevel logLevel, string logLine, string? spanId) + { + // We skip logging for any log level higher (numerically) than the configured log level + if (logLevel > ConfiguredLogLevel) + return; + + var builder = StringBuilderCache.Acquire(); + WriteLogPrefix(managedThreadId, dateTime, logLevel, builder, spanId ?? activity?.SpanId.ToHexString() ?? string.Empty); + builder.Append(logLine); + + if (activity is not null) + { + // Accessing activity.Id here will cause the Id to be initialized + // before the sampler runs in case where the activity is created using legacy way + // i.e. new Activity("Operation name"). This will result in Id not reflecting the + // correct sampling flags + // https://github.com/dotnet/runtime/issues/61857 + + var activityId = $"00-{activity.TraceId.ToHexString()}-{activity.SpanId.ToHexString()}-{(activity.ActivityTraceFlags.HasFlag(ActivityTraceFlags.Recorded) ? "01" : "00")}"; + builder.Append($" <{activityId}>"); + } + + var spin = new SpinWait(); + while (true) + { + if (_channel.Writer.TryWrite(StringBuilderCache.GetStringAndRelease(builder))) + break; + spin.SpinOnce(); + } + } + + private static bool IsFileLoggingEnabled() + { + var enableFileLogging = true; + + var isEnabledValue = Environment.GetEnvironmentVariable(EnvironmentVariables.ElasticOtelFileLogging); + + if (!string.IsNullOrEmpty(isEnabledValue)) + { + if (int.TryParse(isEnabledValue, out var intValue)) + enableFileLogging = intValue == 1; + else if (bool.TryParse(isEnabledValue, out var boolValue)) + enableFileLogging = boolValue; + } + + return enableFileLogging; + } + + private static string GetElasticFolder => + RuntimeInformation.IsOSPlatform(OSPlatform.Windows) ? "Elastic" : "elastic"; + + public void Dispose() + { + // We don't wait for the channel to be drained which is probably the correct choice. + // Dispose should be a quick operation with no chance of exceptions. + // We should document methods to wait for the WritingTask, before disposal, if that matters to the + // consumer. + + _channel.Writer.TryComplete(); + _streamWriter.Dispose(); + } + + public async ValueTask DisposeAsync() + { + // We don't wait for the channel to be drained which is probably the correct choice. + // Dispose should be a quick operation with no chance of exceptions. + // We should document methods to await the WritingTask, before disposal, if that matters to the + // consumer. + + _channel.Writer.TryComplete(); + await _streamWriter.DisposeAsync().ConfigureAwait(false); + } +} diff --git a/src/Elastic.OpenTelemetry/Diagnostics/LogLevel.cs b/src/Elastic.OpenTelemetry/Diagnostics/LogLevel.cs new file mode 100644 index 0000000..1e64591 --- /dev/null +++ b/src/Elastic.OpenTelemetry/Diagnostics/LogLevel.cs @@ -0,0 +1,14 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information +namespace Elastic.OpenTelemetry.Diagnostics; + +internal enum LogLevel +{ + Unknown = 0, + Critical = 1, + Error = 2, + Warning = 3, + Info = 4, + Trace = 5 +} diff --git a/src/Elastic.OpenTelemetry/Diagnostics/LoggerMessages.cs b/src/Elastic.OpenTelemetry/Diagnostics/LoggerMessages.cs new file mode 100644 index 0000000..6d03c06 --- /dev/null +++ b/src/Elastic.OpenTelemetry/Diagnostics/LoggerMessages.cs @@ -0,0 +1,26 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information +using Elastic.OpenTelemetry.Processors; +using Microsoft.Extensions.Logging; + +namespace Elastic.OpenTelemetry.Diagnostics +{ + internal static partial class LoggerMessages + { + public const string TransactionIdProcessorTagAddedLog = + $"{nameof(TransactionIdProcessor)} added 'transaction.id' tag to Activity."; + + [LoggerMessage( + EventId = 1, + Level = Microsoft.Extensions.Logging.LogLevel.Trace, + Message = TransactionIdProcessorTagAddedLog)] + internal static partial void TransactionIdProcessorTagAdded(this ILogger logger); + + [LoggerMessage( + EventId = 100, + Level = Microsoft.Extensions.Logging.LogLevel.Warning, + Message = "Received an unhandled diagnostic event '{EventName}'.")] + internal static partial void UnhandledDiagnosticEvent(this ILogger logger, string eventName); + } +} diff --git a/src/Elastic.OpenTelemetry/Diagnostics/LoggingDiagnosticSourceListener.cs b/src/Elastic.OpenTelemetry/Diagnostics/LoggingDiagnosticSourceListener.cs new file mode 100644 index 0000000..0c4f7bc --- /dev/null +++ b/src/Elastic.OpenTelemetry/Diagnostics/LoggingDiagnosticSourceListener.cs @@ -0,0 +1,26 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information +using System.Diagnostics; + +namespace Elastic.OpenTelemetry.Diagnostics; + +internal sealed class LoggingDiagnosticSourceListener(LogFileWriter logFileWriter) : IObserver +{ + private readonly object _lock = new(); + private readonly LogFileWriter _logFileWriter = logFileWriter; + + public void OnNext(DiagnosticListener listener) + { + if (listener.Name == ElasticOpenTelemetryDiagnosticSource.DiagnosticSourceName) + { + lock (_lock) + listener.Subscribe(new ElasticDiagnosticLoggingObserver(_logFileWriter)); + } + } + + public void OnCompleted() { } + + public void OnError(Exception error) { } +} + diff --git a/src/Elastic.OpenTelemetry/Diagnostics/LoggingEventListener.cs b/src/Elastic.OpenTelemetry/Diagnostics/LoggingEventListener.cs new file mode 100644 index 0000000..4cd0ca5 --- /dev/null +++ b/src/Elastic.OpenTelemetry/Diagnostics/LoggingEventListener.cs @@ -0,0 +1,142 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information +using System.Diagnostics.Tracing; +using System.Text; +using System.Text.RegularExpressions; + +namespace Elastic.OpenTelemetry.Diagnostics; + +internal sealed partial class LoggingEventListener : EventListener, IAsyncDisposable +{ + public const string OpenTelemetrySdkEventSourceNamePrefix = "OpenTelemetry-"; + + private readonly LogFileWriter _logFileWriter; + private readonly EventLevel _eventLevel = EventLevel.Informational; + + [GeneratedRegex("^\\d{2}-[a-f0-9]{32}-[a-f0-9]{16}-\\d{2}$")] + private static partial Regex TraceParentRegex(); + + public LoggingEventListener(LogFileWriter logFileWriter) + { + _logFileWriter = logFileWriter; + + var eventLevel = LogFileWriter.GetConfiguredLogLevel(); + + _eventLevel = eventLevel switch + { + LogLevel.Trace => EventLevel.Verbose, + LogLevel.Info => EventLevel.Informational, + LogLevel.Warning => EventLevel.Warning, + LogLevel.Error => EventLevel.Error, + LogLevel.Critical => EventLevel.Critical, + _ => EventLevel.Informational // fallback to info level + }; + } + + public override void Dispose() + { + _logFileWriter.Dispose(); + base.Dispose(); + } + + public ValueTask DisposeAsync() => _logFileWriter.DisposeAsync(); + + protected override void OnEventSourceCreated(EventSource eventSource) + { + if (eventSource.Name.StartsWith(OpenTelemetrySdkEventSourceNamePrefix, StringComparison.Ordinal)) + EnableEvents(eventSource, _eventLevel, EventKeywords.All); + + base.OnEventSourceCreated(eventSource); + } + + protected override void OnEventWritten(EventWrittenEventArgs eventData) + { + if (!eventData.EventSource.Name.StartsWith(OpenTelemetrySdkEventSourceNamePrefix, StringComparison.Ordinal)) + { + // Workaround for https://github.com/dotnet/runtime/issues/31927 + // EventCounters are published to all EventListeners, regardless of + // which EventSource providers a listener is enabled for. + return; + } + + // This should generally be reasonably efficient but we can consider switching + // to a rented array and Span if required. + var builder = StringBuilderCache.Acquire(); + + var spanId = CreateLogMessage(eventData, builder); + + try + { + // TODO - We can only get the OS thread ID from the args - Do we send that instead?? + // As per this issue - https://github.com/dotnet/runtime/issues/13125 - OnEventWritten may be on a different thread + // so we can't use the Environment.CurrentManagedThreadId value here. + _logFileWriter.WriteLogLine(null, -1, eventData.TimeStamp, GetLogLevel(eventData), StringBuilderCache.GetStringAndRelease(builder), spanId); + } + catch (Exception) + { + // TODO - We might want to block writing further events if we reach here as it's + // likely a file access issue + } + + static LogLevel GetLogLevel(EventWrittenEventArgs eventData) => + eventData.Level switch + { + EventLevel.Critical => LogLevel.Critical, + EventLevel.Error => LogLevel.Error, + EventLevel.Warning => LogLevel.Warning, + EventLevel.Informational => LogLevel.Info, + EventLevel.Verbose => LogLevel.Trace, + EventLevel.LogAlways => LogLevel.Unknown, + _ => LogLevel.Unknown + }; + + static string? CreateLogMessage(EventWrittenEventArgs eventData, StringBuilder builder) + { + string? spanId = null; + + if (eventData.EventSource.Name.StartsWith(OpenTelemetrySdkEventSourceNamePrefix) && eventData.Message is not null) + { + builder.Append($"OTEL-SDK: [{eventData.OSThreadId}] "); + + if (eventData.Payload is null) + { + builder.Append(eventData.Message); + return spanId; + } + + try + { + var matchedActivityId = eventData.Payload.SingleOrDefault(p => p is string ps && TraceParentRegex().IsMatch(ps)); + + if (matchedActivityId is string payloadString) + spanId = payloadString[36..^3]; + + var message = string.Format(eventData.Message, [.. eventData.Payload]); + builder.Append(message); + return spanId; + } + catch + { + for (var i = 0; i < eventData.Payload.Count; i++) + { + builder.Append(" | "); + + var payload = eventData.Payload[i]; + + if (payload is not null) + { + builder.Append(payload.ToString() ?? "null"); + } + else + { + builder.Append("null"); + } + } + } + } + + return spanId; + } + } +} diff --git a/src/Elastic.OpenTelemetry/Diagnostics/StringBuilderCache.cs b/src/Elastic.OpenTelemetry/Diagnostics/StringBuilderCache.cs new file mode 100644 index 0000000..644d7f9 --- /dev/null +++ b/src/Elastic.OpenTelemetry/Diagnostics/StringBuilderCache.cs @@ -0,0 +1,61 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information +using System.Text; + +namespace Elastic.OpenTelemetry.Diagnostics; + +// SOURCE: https://github.com/dotnet/runtime/blob/main/src/libraries/Common/src/System/Text/StringBuilderCache.cs +// Licensed to the .NET Foundation under one or more agreements. +// The .NET Foundation licenses this file to you under the MIT license. +internal static class StringBuilderCache +{ + // The value 360 was chosen in discussion with performance experts as a compromise between using + // as little memory per thread as possible and still covering a large part of short-lived + // StringBuilder creations on the startup path of VS designers. + internal const int MaxBuilderSize = 360; + private const int DefaultCapacity = 64; // At least as large as the prefix + + [ThreadStatic] + private static StringBuilder? CachedInstance; + + /// Get a StringBuilder for the specified capacity. + /// If a StringBuilder of an appropriate size is cached, it will be returned and the cache emptied. + public static StringBuilder Acquire(int capacity = DefaultCapacity) + { + if (capacity <= MaxBuilderSize) + { + var sb = CachedInstance; + if (sb != null) + { + // Avoid StringBuilder block fragmentation by getting a new StringBuilder + // when the requested size is larger than the current capacity + if (capacity <= sb.Capacity) + { + CachedInstance = null; + sb.Clear(); + return sb; + } + } + } + + return new StringBuilder(capacity); + } + + /// Place the specified builder in the cache if it is not too big. + public static void Release(StringBuilder sb) + { + if (sb.Capacity <= MaxBuilderSize) + { + CachedInstance = sb; + } + } + + /// ToString() the StringBuilder, Release it to the cache, and return the resulting string. + public static string GetStringAndRelease(StringBuilder sb) + { + var result = sb.ToString(); + Release(sb); + return result; + } +} diff --git a/src/Elastic.OpenTelemetry/Elastic.OpenTelemetry.csproj b/src/Elastic.OpenTelemetry/Elastic.OpenTelemetry.csproj index fdb9eeb..26d01bd 100644 --- a/src/Elastic.OpenTelemetry/Elastic.OpenTelemetry.csproj +++ b/src/Elastic.OpenTelemetry/Elastic.OpenTelemetry.csproj @@ -18,5 +18,9 @@ + + + + diff --git a/src/Elastic.OpenTelemetry/EnvironmentVariables.cs b/src/Elastic.OpenTelemetry/EnvironmentVariables.cs new file mode 100644 index 0000000..f5fc33c --- /dev/null +++ b/src/Elastic.OpenTelemetry/EnvironmentVariables.cs @@ -0,0 +1,11 @@ +// Licensed to Elasticsearch B.V under one or more agreements. +// Elasticsearch B.V licenses this file to you under the Apache 2.0 License. +// See the LICENSE file in the project root for more information +namespace Elastic.OpenTelemetry; + +internal static class EnvironmentVariables +{ + public const string ElasticOtelFileLogging = "ELASTIC_OTEL_ENABLE_FILE_LOGGING"; + public const string ElasticOtelLogDirectoryEnvironmentVariable = "ELASTIC_OTEL_LOG_DIRECTORY"; + public const string ElasticOtelLogLevelEnvironmentVariable = "ELASTIC_OTEL_LOG_LEVEL"; +} diff --git a/src/Elastic.OpenTelemetry/Extensions/TraceBuilderProviderExtensions.cs b/src/Elastic.OpenTelemetry/Extensions/TraceBuilderProviderExtensions.cs index 55c8440..0a208ee 100644 --- a/src/Elastic.OpenTelemetry/Extensions/TraceBuilderProviderExtensions.cs +++ b/src/Elastic.OpenTelemetry/Extensions/TraceBuilderProviderExtensions.cs @@ -5,22 +5,42 @@ using OpenTelemetry.Exporter; using OpenTelemetry.Trace; using OpenTelemetry; +using System.Diagnostics; +using Elastic.OpenTelemetry.Diagnostics; + +using static Elastic.OpenTelemetry.Diagnostics.ElasticOpenTelemetryDiagnosticSource; namespace Elastic.OpenTelemetry.Extensions; +internal readonly record struct AddProcessorEvent(Type ProcessorType, Type BuilderType); + +internal readonly record struct AddSourceEvent(string ActivitySourceName, Type BuilderType); + /// Provides Elastic APM extensions to public static class TraceBuilderProviderExtensions { - //TODO binder source generator on Build() to make it automatic? + //TODO binder source generator on Build() to make it automatic? /// Include Elastic APM Trace Processors to ensure data is enriched and extended. - public static TracerProviderBuilder AddElasticProcessors(this TracerProviderBuilder builder) => - builder - .AddProcessor(new TransactionIdProcessor()); - - /// - /// Adds the OTLP exporter to the tracer, configured to send data to an Elastic APM backend. - /// - public static TracerProviderBuilder AddElasticOtlpExporter(this TracerProviderBuilder builder) => AddElasticOtlpExporter(builder, null, null); + public static TracerProviderBuilder AddElasticProcessors(this TracerProviderBuilder builder) => + builder.LogAndAddProcessor(new TransactionIdProcessor()); + + internal static TracerProviderBuilder LogAndAddProcessor(this TracerProviderBuilder builder, BaseProcessor processor) + { + Log(ProcessorAddedEvent, () => new DiagnosticEvent(new(processor.GetType(), builder.GetType()))); + return builder.AddProcessor(processor); + } + + internal static TracerProviderBuilder LogAndAddSource(this TracerProviderBuilder builder, string sourceName) + { + Log(SourceAddedEvent, () => new DiagnosticEvent(new(sourceName, builder.GetType()))); + return builder.AddSource(sourceName); + } + + /// + /// Adds the OTLP exporter to the tracer, configured to send data to an Elastic APM backend. + /// + public static TracerProviderBuilder AddElasticOtlpExporter(this TracerProviderBuilder builder) => + AddElasticOtlpExporter(builder, null, null); /// /// Adds the OTLP exporter to the tracer, configured to send data to an Elastic APM backend. @@ -35,6 +55,7 @@ public static TracerProviderBuilder AddElasticProcessors(this TracerProviderBuil public static TracerProviderBuilder AddElasticOtlpExporter(this TracerProviderBuilder builder, Action? configure, string? name) { // TODO - We need a clean way to test this behaviour + // TODO - Logging const string tracesPath = "/v1/traces"; diff --git a/src/Elastic.OpenTelemetry/IAgent.cs b/src/Elastic.OpenTelemetry/IAgent.cs index 65d6668..e1a109f 100644 --- a/src/Elastic.OpenTelemetry/IAgent.cs +++ b/src/Elastic.OpenTelemetry/IAgent.cs @@ -6,6 +6,6 @@ namespace Elastic.OpenTelemetry; /// /// An Elastic OpenTelemetry Distribution agent. /// -public interface IAgent : IDisposable +public interface IAgent : IDisposable, IAsyncDisposable { } diff --git a/src/Elastic.OpenTelemetry/Processors/TransactionIdProcessor.cs b/src/Elastic.OpenTelemetry/Processors/TransactionIdProcessor.cs index 5735069..d64253d 100644 --- a/src/Elastic.OpenTelemetry/Processors/TransactionIdProcessor.cs +++ b/src/Elastic.OpenTelemetry/Processors/TransactionIdProcessor.cs @@ -1,8 +1,12 @@ // Licensed to Elasticsearch B.V under one or more agreements. // Elasticsearch B.V licenses this file to you under the Apache 2.0 License. // See the LICENSE file in the project root for more information -using OpenTelemetry; using System.Diagnostics; +using Elastic.OpenTelemetry.Diagnostics; +using Microsoft.Extensions.Logging; +using OpenTelemetry; + +using static Elastic.OpenTelemetry.Diagnostics.ElasticOpenTelemetryDiagnosticSource; namespace Elastic.OpenTelemetry.Processors; @@ -11,20 +15,24 @@ namespace Elastic.OpenTelemetry.Processors; /// public class TransactionIdProcessor : BaseProcessor { + private ILogger? _logger = null; + private readonly AsyncLocal _currentTransactionId = new(); + /// /// /// - public const string TransactionIdTagName = "transaction.id"; - - private readonly AsyncLocal _currentTransactionId = new(); + public const string TransactionIdTagName = "transaction.id"; - /// - public override void OnStart(Activity activity) - { - if (activity.Parent == null) - _currentTransactionId.Value = activity.SpanId; + /// + public override void OnStart(Activity activity) + { + if (activity.Parent == null) + _currentTransactionId.Value = activity.SpanId; - if (_currentTransactionId.Value.HasValue) - activity.SetTag(TransactionIdTagName, _currentTransactionId.Value.Value.ToString()); - } + if (_currentTransactionId.Value.HasValue) + { + activity.SetTag(TransactionIdTagName, _currentTransactionId.Value.Value.ToString()); + Log(TransactionIdAddedEvent, () => DiagnosticEvent.Create(ref _logger, activity)); + } + } } diff --git a/tests/Directory.Build.props b/tests/Directory.Build.props index 9bf0584..79246d4 100644 --- a/tests/Directory.Build.props +++ b/tests/Directory.Build.props @@ -2,6 +2,9 @@ + true + $(SolutionRoot)\build\keys\keypair.snk + True