diff --git a/docs/troubleshooting.asciidoc b/docs/troubleshooting.asciidoc index 5fcb5e031..d55cef742 100644 --- a/docs/troubleshooting.asciidoc +++ b/docs/troubleshooting.asciidoc @@ -46,15 +46,55 @@ This means the Agent will pick up the configured logging provider and log as any [[collect-logs-classic]] ==== ASP.NET Classic -Unlike ASP.NET Core, ASP.NET (classic) does not have a predefined logging system. -However, if you have a logging system in place, like NLog, Serilog, or similar, you can direct the agent logs into your -logging system by creating a bridge between the agent's internal logger and your logging system. +ASP.NET (classic) does not have a predefined logging system. By default, the agent is configured to +emit log messages to a +https://docs.microsoft.com/en-us/dotnet/api/system.diagnostics.tracesource[`System.Diagnostics.TraceSource`] +with the source name `"Elastic.Apm"`. The TraceSource adheres to the log levels defined in the +APM agent configuration. + +[IMPORTANT] +-- +System.Diagnostics.TraceSource requires the https://docs.microsoft.com/en-us/dotnet/framework/debug-trace-profile/how-to-compile-conditionally-with-trace-and-debug[`TRACE` compiler directive to be specified], which is specified +by default for both Debug and Release build configurations. +-- + +https://docs.microsoft.com/en-us/dotnet/api/system.diagnostics.tracelistener[TraceListeners] +can be configured to monitor log messages for the trace source, using the https://docs.microsoft.com/en-us/dotnet/framework/configure-apps/file-schema/trace-debug/system-diagnostics-element[``] section of +web.config. For example, the following web.config section writes Elastic.Apm log messages to a file +named my_log_file.log: + +[source,xml] +---- + + + + + <1> + + + + + + + +---- +<1> Define listeners under a source with name `"Elastic.Apm"` to capture agent logs + +[float] +[[collect-logs-class-other-logging-systems]] +===== Other logging systems + +If you have a logging system in place such as https://nlog-project.org/[NLog], https://serilog.net/[Serilog], +or similar, you can direct the agent logs into your logging system by creating an adapter between +the agent's internal logger and your logging system. First implement the `IApmLogger` interface from the `Elastic.Apm.Logging` namespace: [source,csharp] ---- -internal class ApmLoggerBridge : IApmLogger +internal class ApmLoggerAdapter : IApmLogger { private readonly Lazy _logger; public bool IsEnabled(ApmLogLevel level) @@ -71,31 +111,44 @@ internal class ApmLoggerBridge : IApmLogger } ---- -An example implementation for NLog can be seen https://github.com/elastic/apm-agent-dotnet/blob/master/sample/AspNetFullFrameworkSampleApp/App_Start/ApmLoggerToNLog.cs[in our GitHub repository]. - -Then tell the agent to use the `ApmLoggerBridge`. +An example implementation for NLog can be seen https://github.com/elastic/apm-agent-dotnet/blob/f6a33a185675b7b918af59d3333d94b32329a84a/sample/AspNetFullFrameworkSampleApp/App_Start/ApmLoggerToNLog.cs[in our GitHub repository]. -For this in ASP.NET (classic) you need to place the following code into the `Application_Start` method in the `HttpApplication` implementation of your app which is typically in the `Global.asx.cs` file: +Then tell the agent to use the `ApmLoggerAdapter`. For ASP.NET (classic), place the following code into the `Application_Start` +method in the `HttpApplication` implementation of your app which is typically in the `Global.asax.cs` file: [source,csharp] ---- -AgentDependencies.Logger = new ApmLoggerBridge(); +using Elastic.Apm.AspNetFullFramework; + +namespace MyApp +{ + public class MyApplication : HttpApplication + { + protected void Application_Start() + { + AgentDependencies.Logger = new ApmLoggerAdapter(); + + // other application setup... + } + } +} ---- -The `AgentDependencies` class lives in the `Elastic.Apm.AspNetFullFramework` namespace. -During initialization, the agent checks if an additional logger was configured--the agent only does this once, so it's important to set it as early in the process as possible (typically in the `Application_Start` method). +During initialization, the agent checks if an additional logger was configured-- the agent only does this once, so it's important +to set it as early in the process as possible, typically in the `Application_Start` method. [float] [[collect-logs-general]] ==== General .NET applications -If none of the above cases apply to your application, you can still use a bridge and redirect agent logs into a .NET logging system (like NLog, Serilog, or similar). +If none of the above cases apply to your application, you can still use a logger adapter and redirect agent logs into a .NET +logging system like NLog, Serilog, or similar. For this you'll need an `IApmLogger` implementation (see above) which you need to pass to the `Setup` method during agent setup: [source,csharp] ---- -Agent.Setup(new AgentComponents(logger: new ApmLoggerBridge())); +Agent.Setup(new AgentComponents(logger: new ApmLoggerAdapter())); ---- [float] diff --git a/sample/AspNetFullFrameworkSampleApp/App_Start/LoggingConfig.cs b/sample/AspNetFullFrameworkSampleApp/App_Start/LoggingConfig.cs index bd3f788ef..6b2ec90af 100644 --- a/sample/AspNetFullFrameworkSampleApp/App_Start/LoggingConfig.cs +++ b/sample/AspNetFullFrameworkSampleApp/App_Start/LoggingConfig.cs @@ -26,8 +26,6 @@ public class LoggingConfig public static void SetupLogging() { - var logFileEnvVarValue = Environment.GetEnvironmentVariable(LogFileEnvVarName); - var config = new LoggingConfiguration(); const string layout = "${date:format=yyyy-MM-dd HH\\:mm\\:ss.fff zzz}" + " | ${level:uppercase=true:padding=-5}" + // negative values cause right padding @@ -41,6 +39,7 @@ public static void SetupLogging() new PrefixingTraceTarget($"Elastic APM .NET {nameof(AspNetFullFrameworkSampleApp)}> "), LogMemoryTarget, new ConsoleTarget() }; + var logFileEnvVarValue = Environment.GetEnvironmentVariable(LogFileEnvVarName); if (logFileEnvVarValue != null) logTargets.Add(new FileTarget { FileName = logFileEnvVarValue, DeleteOldFileOnStartup = true }); foreach (var logTarget in logTargets) logTarget.Layout = layout; diff --git a/sample/AspNetFullFrameworkSampleApp/Global.asax.cs b/sample/AspNetFullFrameworkSampleApp/Global.asax.cs index 9d1f2b182..56b3a7473 100644 --- a/sample/AspNetFullFrameworkSampleApp/Global.asax.cs +++ b/sample/AspNetFullFrameworkSampleApp/Global.asax.cs @@ -14,21 +14,21 @@ using System.Web.Routing; using AspNetFullFrameworkSampleApp.Mvc; using Elastic.Apm; -using NLog; - +using NLog; + namespace AspNetFullFrameworkSampleApp { public class MvcApplication : HttpApplication { protected void Application_Start() - { - LoggingConfig.SetupLogging(); - - var logger = LogManager.GetCurrentClassLogger(); - logger.Info("Current process ID: {ProcessID}, ELASTIC_APM_SERVER_URLS: {ELASTIC_APM_SERVER_URLS}", - Process.GetCurrentProcess().Id, Environment.GetEnvironmentVariable("ELASTIC_APM_SERVER_URLS")); - - // Web API setup + { + LoggingConfig.SetupLogging(); + + var logger = LogManager.GetCurrentClassLogger(); + logger.Info("Current process ID: {ProcessID}, ELASTIC_APM_SERVER_URLS: {ELASTIC_APM_SERVER_URLS}", + Process.GetCurrentProcess().Id, Environment.GetEnvironmentVariable("ELASTIC_APM_SERVER_URLS")); + + // Web API setup HttpBatchHandler batchHandler = new DefaultHttpBatchHandler(GlobalConfiguration.DefaultServer) { ExecutionOrder = BatchExecutionOrder.NonSequential diff --git a/src/Elastic.Apm.AspNetFullFramework/ElasticApmModule.cs b/src/Elastic.Apm.AspNetFullFramework/ElasticApmModule.cs index 596f5c76a..ae4f590a5 100644 --- a/src/Elastic.Apm.AspNetFullFramework/ElasticApmModule.cs +++ b/src/Elastic.Apm.AspNetFullFramework/ElasticApmModule.cs @@ -6,12 +6,14 @@ using System.Collections; using System.Collections.Generic; using System.Collections.Specialized; +using System.Configuration; using System.Linq; using System.Security.Claims; using System.Web; using Elastic.Apm.Api; using Elastic.Apm.AspNetFullFramework.Extensions; using Elastic.Apm.AspNetFullFramework.Helper; +using Elastic.Apm.Config; using Elastic.Apm.DiagnosticSource; using Elastic.Apm.Helpers; using Elastic.Apm.Logging; @@ -416,12 +418,22 @@ private static bool InitOnceForAllInstancesUnderLock(string dbgInstanceName) => Agent.Instance.Subscribe(new HttpDiagnosticsSubscriber()); }) ?? false; - private static IApmLogger BuildLogger() => AgentDependencies.Logger ?? ConsoleLogger.Instance; + private static IApmLogger CreateDefaultLogger() + { + var logLevel = ConfigurationManager.AppSettings[ConfigConsts.KeyNames.LogLevel]; + if (string.IsNullOrEmpty(logLevel)) + logLevel = Environment.GetEnvironmentVariable(ConfigConsts.EnvVarNames.LogLevel); + + var level = ConfigConsts.DefaultValues.LogLevel; + if (!string.IsNullOrEmpty(logLevel)) + Enum.TryParse(logLevel, true, out level); + + return new TraceLogger(level); + } private static AgentComponents CreateAgentComponents(string dbgInstanceName) { - var rootLogger = BuildLogger(); - + var rootLogger = AgentDependencies.Logger ?? CreateDefaultLogger(); var reader = ConfigHelper.CreateReader(rootLogger) ?? new FullFrameworkConfigReader(rootLogger); var agentComponents = new FullFrameworkAgentComponents(rootLogger, reader); diff --git a/src/Elastic.Apm/Config/AbstractConfigurationReader.cs b/src/Elastic.Apm/Config/AbstractConfigurationReader.cs index cac132ac1..07020acbd 100644 --- a/src/Elastic.Apm/Config/AbstractConfigurationReader.cs +++ b/src/Elastic.Apm/Config/AbstractConfigurationReader.cs @@ -213,15 +213,15 @@ protected LogLevel ParseLogLevel(ConfigurationKeyValue kv) if (TryParseLogLevel(kv?.Value, out var level)) return level; if (kv?.Value == null) - _logger?.Debug()?.Log("No log level provided. Defaulting to log level '{DefaultLogLevel}'", ConsoleLogger.DefaultLogLevel); + _logger?.Debug()?.Log("No log level provided. Defaulting to log level '{DefaultLogLevel}'", DefaultValues.LogLevel); else { _logger?.Error() ?.Log("Failed parsing log level from {Origin}: {Key}, value: {Value}. Defaulting to log level '{DefaultLogLevel}'", - kv.ReadFrom, kv.Key, kv.Value, ConsoleLogger.DefaultLogLevel); + kv.ReadFrom, kv.Key, kv.Value, DefaultValues.LogLevel); } - return ConsoleLogger.DefaultLogLevel; + return DefaultValues.LogLevel; } protected Uri ParseServerUrl(ConfigurationKeyValue kv) => diff --git a/src/Elastic.Apm/Config/ConfigConsts.cs b/src/Elastic.Apm/Config/ConfigConsts.cs index 438a18a9a..8dc19dc68 100644 --- a/src/Elastic.Apm/Config/ConfigConsts.cs +++ b/src/Elastic.Apm/Config/ConfigConsts.cs @@ -6,6 +6,7 @@ using System.Collections.Generic; using Elastic.Apm.Cloud; using Elastic.Apm.Helpers; +using Elastic.Apm.Logging; namespace Elastic.Apm.Config { @@ -25,6 +26,7 @@ public static class DefaultValues public const bool CentralConfig = true; public const string CloudProvider = SupportedValues.CloudProviderAuto; public const int FlushIntervalInMilliseconds = 10_000; // 10 seconds + public const LogLevel LogLevel = Logging.LogLevel.Error; public const int MaxBatchEventCount = 10; public const int MaxQueueEventCount = 1000; public const string MetricsInterval = "30s"; diff --git a/src/Elastic.Apm/Logging/ConsoleLogger.cs b/src/Elastic.Apm/Logging/ConsoleLogger.cs index 1cb7ab7de..b214fefe8 100644 --- a/src/Elastic.Apm/Logging/ConsoleLogger.cs +++ b/src/Elastic.Apm/Logging/ConsoleLogger.cs @@ -4,13 +4,14 @@ using System; using System.IO; +using Elastic.Apm.Config; +using static Elastic.Apm.Config.ConfigConsts; namespace Elastic.Apm.Logging { internal class ConsoleLogger : IApmLogger, ILogLevelSwitchable { private static readonly object SyncRoot = new object(); - internal static readonly LogLevel DefaultLogLevel = LogLevel.Error; private readonly TextWriter _errorOut; private readonly TextWriter _standardOut; @@ -22,7 +23,7 @@ public ConsoleLogger(LogLevel level, TextWriter standardOut = null, TextWriter e _errorOut = errorOut ?? Console.Error; } - public static ConsoleLogger Instance { get; } = new ConsoleLogger(DefaultLogLevel); + public static ConsoleLogger Instance { get; } = new ConsoleLogger(DefaultValues.LogLevel); public LogLevelSwitch LogLevelSwitch { get; } @@ -30,7 +31,7 @@ public ConsoleLogger(LogLevel level, TextWriter standardOut = null, TextWriter e public static ConsoleLogger LoggerOrDefault(LogLevel? level) { - if (level.HasValue && level.Value != DefaultLogLevel) + if (level.HasValue && level.Value != DefaultValues.LogLevel) return new ConsoleLogger(level.Value); return Instance; diff --git a/src/Elastic.Apm/Logging/TraceLogger.cs b/src/Elastic.Apm/Logging/TraceLogger.cs new file mode 100644 index 000000000..d867f6e08 --- /dev/null +++ b/src/Elastic.Apm/Logging/TraceLogger.cs @@ -0,0 +1,101 @@ +// 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; +using System.Diagnostics; +using System.Runtime.CompilerServices; +using System.Text; +using Elastic.Apm.Helpers; + +namespace Elastic.Apm.Logging +{ + /// + /// A logging implementation that logs to a with the source name Elastic.Apm + /// + internal class TraceLogger : IApmLogger, ILogLevelSwitchable + { + private const string SourceName = "Elastic.Apm"; + + private static readonly TraceSource TraceSource; + + static TraceLogger() => TraceSource = new TraceSource(SourceName); + + public TraceLogger(LogLevel level) => LogLevelSwitch = new LogLevelSwitch(level); + + public LogLevelSwitch LogLevelSwitch { get; } + + private LogLevel Level => LogLevelSwitch.Level; + + public bool IsEnabled(LogLevel level) => Level <= level; + + public void Log(LogLevel level, TState state, Exception e, Func formatter) + { + if (!IsEnabled(level)) return; + + var message = formatter(state, e); + var logLevel = LevelToString(level); + + StringBuilder builder; + string exceptionType = null; + var capacity = 51 + message.Length + logLevel.Length; + + if (e is null) + builder = new StringBuilder(capacity); + else + { + exceptionType = e.GetType().FullName; + builder = new StringBuilder(capacity + exceptionType.Length + e.Message.Length + e.StackTrace.Length); + } + + builder.Append('[') + .Append(DateTime.Now.ToString("yyyy-MM-dd HH:mm:ss.fff zzz")) + .Append("][") + .Append(logLevel) + .Append("] - ") + .Append(message); + + if (e != null) + { + builder.Append("+-> Exception: ") + .Append(exceptionType) + .Append(": ") + .AppendLine(e.Message) + .AppendLine(e.StackTrace); + } + + var logMessage = builder.ToString(); + for (var i = 0; i < TraceSource.Listeners.Count; i++) + { + var listener = TraceSource.Listeners[i]; + if (!listener.IsThreadSafe) + { + lock (listener) + listener.WriteLine(logMessage); + } + else + listener.WriteLine(logMessage); + } + + TraceSource.Flush(); + } + + [MethodImpl(MethodImplOptions.AggressiveInlining)] + internal static string LevelToString(LogLevel level) + { + switch (level) + { + case LogLevel.Error: return "Error"; + case LogLevel.Warning: return "Warning"; + case LogLevel.Information: return "Info"; + case LogLevel.Debug: return "Debug"; + case LogLevel.Trace: return "Trace"; + case LogLevel.Critical: return "Critical"; + // ReSharper disable once RedundantCaseLabel + case LogLevel.None: + default: return "None"; + } + } + } +} diff --git a/test/Elastic.Apm.AspNetFullFramework.Tests/HttpContextCurrentExecutionSegmentsContainerTests.cs b/test/Elastic.Apm.AspNetFullFramework.Tests/HttpContextCurrentExecutionSegmentsContainerTests.cs index e7db33d55..6120feab4 100644 --- a/test/Elastic.Apm.AspNetFullFramework.Tests/HttpContextCurrentExecutionSegmentsContainerTests.cs +++ b/test/Elastic.Apm.AspNetFullFramework.Tests/HttpContextCurrentExecutionSegmentsContainerTests.cs @@ -38,9 +38,8 @@ public async Task Transaction_And_Spans_Captured_When_Large_Request() bytes.Should().BeGreaterThan(20_000); var content = new StringContent(json, Encoding.UTF8, "application/json"); - var client = new HttpClient(); var bulkSamplesUri = Consts.SampleApp.CreateUrl("/Database/Bulk"); - var response = await client.PostAsync(bulkSamplesUri, content).ConfigureAwait(false); + var response = await HttpClient.PostAsync(bulkSamplesUri, content).ConfigureAwait(false); var responseContent = await response.Content.ReadAsStringAsync(); response.IsSuccessStatusCode.Should().BeTrue(responseContent); @@ -62,9 +61,8 @@ public async Task Transaction_And_Spans_Captured_When_Controller_Action_Makes_As var count = 100; var content = new StringContent($"{{\"count\":{count}}}", Encoding.UTF8, "application/json"); - var client = new HttpClient(); var bulkSamplesUri = Consts.SampleApp.CreateUrl("/Database/Generate"); - var response = await client.PostAsync(bulkSamplesUri, content).ConfigureAwait(false); + var response = await HttpClient.PostAsync(bulkSamplesUri, content).ConfigureAwait(false); var responseContent = await response.Content.ReadAsStringAsync(); response.IsSuccessStatusCode.Should().BeTrue(responseContent); diff --git a/test/Elastic.Apm.Tests.Utilities/TestingConfig.cs b/test/Elastic.Apm.Tests.Utilities/TestingConfig.cs index 091ace83a..931546e18 100644 --- a/test/Elastic.Apm.Tests.Utilities/TestingConfig.cs +++ b/test/Elastic.Apm.Tests.Utilities/TestingConfig.cs @@ -10,6 +10,7 @@ using Elastic.Apm.Helpers; using Elastic.Apm.Logging; using Xunit.Abstractions; +using static Elastic.Apm.Config.ConfigConsts; namespace Elastic.Apm.Tests.Utilities { @@ -23,10 +24,10 @@ internal static class Options private const string SharedPrefix = "Elastic APM .NET Tests> {0}> "; internal static LogLevelOptionMetadata LogLevel = new LogLevelOptionMetadata( - "ELASTIC_APM_TESTS_LOG_LEVEL", ConsoleLogger.DefaultLogLevel, x => x.LogLevel); + "ELASTIC_APM_TESTS_LOG_LEVEL", DefaultValues.LogLevel, x => x.LogLevel); internal static LogLevelOptionMetadata LogLevelForTestingConfigParsing = new LogLevelOptionMetadata( - "ELASTIC_APM_TESTS_LOG_LEVEL_FOR_TESTING_CONFIG_PARSING", ConsoleLogger.DefaultLogLevel, x => x.LogLevelForTestingConfigParsing); + "ELASTIC_APM_TESTS_LOG_LEVEL_FOR_TESTING_CONFIG_PARSING", DefaultValues.LogLevel, x => x.LogLevelForTestingConfigParsing); internal static BoolOptionMetadata LogToConsoleEnabled = new BoolOptionMetadata( "ELASTIC_APM_TESTS_LOG_CONSOLE_ENABLED", !IsRunningInIde, x => x.LogToConsoleEnabled); @@ -238,7 +239,7 @@ internal class MutableSnapshot : ISnapshot internal MutableSnapshot(IRawConfigSnapshot rawConfigSnapshot, ITestOutputHelper xUnitOutputHelper) { - var tempLogger = BuildXunitOutputLogger(ConsoleLogger.DefaultLogLevel); + var tempLogger = BuildXunitOutputLogger(DefaultValues.LogLevel); Options.LogLevelForTestingConfigParsing.ParseAndSetProperty(rawConfigSnapshot, this, tempLogger); var parsingLogger = BuildXunitOutputLogger(LogLevelForTestingConfigParsing);