Use TraceLogger as default logger in ASP.NET Full Framework

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[`<system.diagnostics>`] 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]
+----
+<configuration>
+  <!-- other sections .... -->
+<system.diagnostics>
+	<sources>
+		<source name="Elastic.Apm"> <1>
+			<listeners>
+				<add name="file" 
+					type="System.Diagnostics.TextWriterTraceListener" 
+					initializeData="my_log_file.log" />
+			</listeners>
+		</source>
+	</sources>
+</system.diagnostics>
+</configuration>  
+----
+<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> _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]

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;

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

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);
 

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) =>

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";

src/Elastic.Apm/Helpers/StringBuilderCache.cs

@@ -0,0 +1,65 @@
+// Licensed to the .NET Foundation under one or more agreements.
+// The .NET Foundation licenses this file to you under the MIT license.
+// See the LICENSE file in the project root for more information.
+
+// 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.Text;
+
+namespace Elastic.Apm.Helpers
+{
+	/// <summary>Provide a cached reusable instance of stringbuilder per thread.</summary>
+	internal static class StringBuilderCache
+	{
+		private const int DefaultCapacity = 16; // == StringBuilder.DefaultCapacity
+
+		// 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.
+		private const int MaxBuilderSize = 360;
+
+		[ThreadStatic]
+		private static StringBuilder _cachedInstance;
+
+		/// <summary>Get a StringBuilder for the specified capacity.</summary>
+		/// <remarks>If a StringBuilder of an appropriate size is cached, it will be returned and the cache emptied.</remarks>
+		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);
+		}
+
+		/// <summary>Place the specified builder in the cache if it is not too big.</summary>
+		public static void Release(StringBuilder sb)
+		{
+			if (sb.Capacity <= MaxBuilderSize) _cachedInstance = sb;
+		}
+
+		/// <summary>ToString() the stringbuilder, Release it to the cache, and return the resulting string.</summary>
+		public static string GetStringAndRelease(StringBuilder sb)
+		{
+			var result = sb.ToString();
+			Release(sb);
+			return result;
+		}
+	}
+}

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,15 +23,15 @@ 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; }
 
 		private LogLevel Level => LogLevelSwitch.Level;
 
 		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;