Improve logging and profiler diagnostics

src/Elastic.Apm/AgentComponents.cs

@@ -6,6 +6,7 @@
 using System.Collections;
 using System.Collections.Generic;
 using System.Diagnostics;
+using System.Threading;
 using Elastic.Apm.Api;
 using Elastic.Apm.BackendComm.CentralConfig;
 using Elastic.Apm.Config;
@@ -234,14 +235,22 @@ internal static IApmLogger GetGlobalLogger(IApmLogger fallbackLogger, LogLevel a
 				}
 
 				var effectiveLogLevel = LogLevelUtils.GetFinest(agentLogLevel, fileLogConfig.LogLevel);
-				if ((fileLogConfig.LogTargets & GlobalLogTarget.File) == GlobalLogTarget.File)
-					TraceLogger.TraceSource.Listeners.Add(new TextWriterTraceListener(fileLogConfig.AgentLogFilePath));
-				if ((fileLogConfig.LogTargets & GlobalLogTarget.StdOut) == GlobalLogTarget.StdOut)
-					TraceLogger.TraceSource.Listeners.Add(new TextWriterTraceListener(Console.Out));
-
-				var logger = new TraceLogger(effectiveLogLevel);
-				logger.Info()?.Log($"{nameof(fileLogConfig)} - {fileLogConfig}");
-				return logger;
+
+				// Guard against multiple calls within the same AppDomain (e.g. CreateDefaultLogger on .NET Framework
+				// calls GetGlobalLogger, then AgentComponents calls it again via the constructor). Without this guard
+				// each call would add a new TextWriterTraceListener to the shared static TraceSource, producing one
+				// log file per call instead of one per AppDomain.
+				if (Interlocked.Exchange(ref _fileLoggingSetupDone, 1) == 0)
+				{
+					if ((fileLogConfig.LogTargets & GlobalLogTarget.File) == GlobalLogTarget.File)
+						TraceLogger.TraceSource.Listeners.Add(new TextWriterTraceListener(fileLogConfig.AgentLogFilePath));
+					if ((fileLogConfig.LogTargets & GlobalLogTarget.StdOut) == GlobalLogTarget.StdOut)
+						TraceLogger.TraceSource.Listeners.Add(new TextWriterTraceListener(Console.Out));
+
+					WriteFileHeader(fileLogConfig);
+				}
+
+				return new TraceLogger(effectiveLogLevel);
 			}
 			catch (Exception e)
 			{
@@ -250,6 +259,37 @@ internal static IApmLogger GetGlobalLogger(IApmLogger fallbackLogger, LogLevel a
 			return fallbackLogger;
 		}
 
+		// Written once per AppDomain at file-logging setup time, bypassing the log-level filter so it always
+		// appears at the top of every agent.log regardless of the configured level.
+		private static void WriteFileHeader(GlobalLogConfiguration fileLogConfig)
+		{
+			var now = DateTime.Now;
+			var tid = Environment.CurrentManagedThreadId;
+
+			void Emit(string message)
+			{
+				var line = $"[{now:yyyy-MM-dd HH:mm:ss.fff zzz}][{tid}][Info] - {message}";
+				for (var i = 0; i < TraceLogger.TraceSource.Listeners.Count; i++)
+				{
+					var listener = TraceLogger.TraceSource.Listeners[i];
+					if (!listener.IsThreadSafe)
+						lock (listener)
+							listener.WriteLine(line);
+					else
+						listener.WriteLine(line);
+				}
+			}
+
+			Emit($"fileLogConfig - {fileLogConfig}");
+			Emit($"AppDomain ID: {AppDomain.CurrentDomain.Id}");
+			Emit($"AppDomain Name: {AppDomain.CurrentDomain.FriendlyName}");
+			Emit($"AppDomain BaseDirectory: {AppDomain.CurrentDomain.BaseDirectory}");
+			Emit($"AppDomain IsDefault: {AppDomain.CurrentDomain.IsDefaultAppDomain()}");
+			TraceLogger.TraceSource.Flush();
+		}
+
+		private static int _fileLoggingSetupDone = 0;
+
 #if NET || NETSTANDARD2_1
 		internal ElasticActivityListener ElasticActivityListener { get; }
 #endif

src/Elastic.Apm/Config/ConfigurationLogger.cs

@@ -69,6 +69,40 @@ public static void PrintAgentLogPreamble(IApmLogger logger, IConfigurationReader
 				info.Log("Process ID: {ProcessId}", Process.GetCurrentProcess().Id);
 				info.Log("Process Name: {ProcessName}", Process.GetCurrentProcess().ProcessName);
 				info.Log("Command line arguments: '{ProcessArguments}'", string.Join(", ", System.Environment.GetCommandLineArgs()));
+				info.Log("AppDomain ID: {AppDomainId}", AppDomain.CurrentDomain.Id);
+				info.Log("AppDomain Name: {AppDomainFriendlyName}", AppDomain.CurrentDomain.FriendlyName);
+				info.Log("AppDomain BaseDirectory: {AppDomainBaseDirectory}", AppDomain.CurrentDomain.BaseDirectory);
+				info.Log("AppDomain IsDefault: {AppDomainIsDefault}", AppDomain.CurrentDomain.IsDefaultAppDomain());
+#if NETFRAMEWORK
+				try
+				{
+					info.Log("AppDomain Config File: {AppDomainConfigFile}", AppDomain.CurrentDomain.SetupInformation.ConfigurationFile);
+					info.Log("AppDomain Shadow Copy: {AppDomainShadowCopy}", AppDomain.CurrentDomain.SetupInformation.ShadowCopyFiles);
+				}
+				catch (Exception e)
+				{
+					info.Log("AppDomain setup info unavailable: {Error}", e.Message);
+				}
+				// Reflect against System.Web only if it is already loaded — avoids pulling the assembly into
+				// non-IIS processes (console apps, Windows services) where it has no business being loaded.
+				try
+				{
+					var systemWebAssembly = AppDomain.CurrentDomain.GetAssemblies()
+						.FirstOrDefault(a => string.Equals(a.GetName().Name, "System.Web", StringComparison.OrdinalIgnoreCase));
+					var hostingEnvType = systemWebAssembly?.GetType("System.Web.Hosting.HostingEnvironment");
+					var isHosted = hostingEnvType != null && (bool)(hostingEnvType.GetProperty("IsHosted")?.GetValue(null) ?? false);
+					info.Log("IIS Hosted: {IisHosted}", isHosted);
+					if (isHosted)
+					{
+						info.Log("IIS Site Name: {IisSiteName}", hostingEnvType.GetProperty("SiteName")?.GetValue(null) ?? "<unknown>");
+						info.Log("IIS Application Virtual Path: {IisVirtualPath}", hostingEnvType.GetProperty("ApplicationVirtualPath")?.GetValue(null) ?? "<unknown>");
+					}
+				}
+				catch (Exception e)
+				{
+					info.Log("IIS hosting info unavailable: {Error}", e.Message);
+				}
+#endif
 				info.Log("Operating System: {OSDescription}", RuntimeInformation.OSDescription);
 				info.Log("CPU architecture: {OSArchitecture}", RuntimeInformation.OSArchitecture);
 				info.Log("Host: {HostName}", System.Environment.MachineName);

src/Elastic.Apm/Logging/GlobalLogConfiguration.cs

@@ -5,6 +5,7 @@
 using System;
 using System.Collections;
 using System.Diagnostics;
+using System.Globalization;
 using System.IO;
 using System.Linq;
 
@@ -194,7 +195,9 @@ internal static GlobalLogConfiguration FromEnvironment(IDictionary environmentVa
 	private static string GetLogFilePrefix()
 	{
 		var process = Process.GetCurrentProcess();
-		return $"{process.ProcessName}_{process.Id}_{Environment.TickCount}";
+		var appDomainId = AppDomain.CurrentDomain.Id;
+		var timestamp = DateTime.UtcNow.ToString("yyyyMMddTHHmmssfff", CultureInfo.InvariantCulture);
+		return $"{process.ProcessName}_{process.Id}_ad{appDomainId}_{timestamp}";
 	}
 
 	public string CreateLogFileName(string applicationName = "agent")

src/profiler/Elastic.Apm.Profiler.Managed.Loader/Startup.NetCore.cs

@@ -54,27 +54,40 @@ private static Assembly ResolveDependencies(object sender, ResolveEventArgs args
 
 			Logger.Log(LogLevel.Trace, "Probing: {0}, exists on disk: {1}", path, exists);
 
+			if (!exists)
+			{
+				Logger.Log(LogLevel.Debug, "AssemblyResolve: {0} not found in profiler directory, returning null", assemblyName.Name);
+				return null;
+			}
+
             // Only load the main Elastic.Apm.Profiler.Managed.dll into the default Assembly Load Context.
             // If Elastic.Apm or other libraries are provided by the NuGet package, their loads are handled in the following two ways.
             // 1) The AssemblyVersion is greater than or equal to the version used by Elastic.Apm.Profiler.Managed, the assembly
             //    will load successfully and will not invoke this resolve event.
             // 2) The AssemblyVersion is lower than the version used by Elastic.Apm.Profiler.Managed, the assembly will fail to load
             //    and invoke this resolve event. It must be loaded in a separate AssemblyLoadContext since the application will only
             //    load the originally referenced version
-			if (exists)
+			try
 			{
 				if (assemblyName.Name.StartsWith("Elastic.Apm.Profiler.Managed", StringComparison.OrdinalIgnoreCase)
 					&& assemblyName.FullName.IndexOf("PublicKeyToken=ae7400d2c189cf22", StringComparison.OrdinalIgnoreCase) >= 0)
 				{
-					Logger.Log(LogLevel.Debug, "Loading {0} assembly using Assembly.LoadFrom", assemblyName);
-					return Assembly.LoadFrom(path);
+					Logger.Log(LogLevel.Debug, "Loading {0} assembly using Assembly.LoadFrom", assemblyName.Name);
+					var assembly = Assembly.LoadFrom(path);
+					Logger.Log(LogLevel.Debug, "Loaded {0} from {1}", assemblyName.Name, assembly.Location);
+					return assembly;
 				}
 
-				Logger.Log(LogLevel.Debug, "Loading {0} assembly using DependencyLoadContext.LoadFromAssemblyPath", assemblyName);
-				return DependencyLoadContext.LoadFromAssemblyPath(path);
+				Logger.Log(LogLevel.Debug, "Loading {0} assembly using DependencyLoadContext.LoadFromAssemblyPath", assemblyName.Name);
+				var depAssembly = DependencyLoadContext.LoadFromAssemblyPath(path);
+				Logger.Log(LogLevel.Debug, "Loaded {0} from {1}", assemblyName.Name, depAssembly.Location);
+				return depAssembly;
+			}
+			catch (Exception e)
+			{
+				Logger.Log(LogLevel.Error, e, "AssemblyResolve: failed to load {0} from {1}", assemblyName.Name, path);
+				return null;
 			}
-
-			return null;
         }
     }
 

src/profiler/Elastic.Apm.Profiler.Managed.Loader/Startup.NetFramework.cs

@@ -53,10 +53,13 @@ private static bool IsNet472OrHigher()
 				// Release value 461808 corresponds to .NET Framework 4.7.2 on Windows 10 1803+;
 				// 461814 is the value for all other OS versions. Checking >= 461808 covers both.
 				var release = Convert.ToInt32(key?.GetValue("Release") ?? 0);
-				return release >= 461808;
+				var result = release >= 461808;
+				Logger.Log(LogLevel.Debug, "IsNet472OrHigher: registry release={0}, result={1}", release, result);
+				return result;
 			}
-			catch
+			catch (Exception e)
 			{
+				Logger.Log(LogLevel.Warning, e, "IsNet472OrHigher: failed to read registry, assuming false");
 				return false;
 			}
 		}
@@ -78,13 +81,24 @@ private static Assembly ResolveDependencies(object sender, ResolveEventArgs args
 
 			Logger.Log(LogLevel.Trace, "Probing: {0}, exists on disk: {1}", path, exists);
 
-			if (exists)
+			if (!exists)
 			{
-				Logger.Log(LogLevel.Debug, "Loading {0} assembly", assemblyName);
-				return Assembly.LoadFrom(path);
+				Logger.Log(LogLevel.Debug, "AssemblyResolve: {0} not found in profiler directory, returning null", assemblyName);
+				return null;
 			}
 
-			return null;
+			try
+			{
+				Logger.Log(LogLevel.Debug, "Loading {0} assembly from {1}", assemblyName, path);
+				var assembly = Assembly.LoadFrom(path);
+				Logger.Log(LogLevel.Debug, "Loaded {0} from {1}", assemblyName, assembly.Location);
+				return assembly;
+			}
+			catch (Exception e)
+			{
+				Logger.Log(LogLevel.Error, e, "AssemblyResolve: failed to load {0} from {1}", assemblyName, path);
+				return null;
+			}
 		}
 	}
 }

src/profiler/Elastic.Apm.Profiler.Managed.Loader/Startup.cs

@@ -16,12 +16,18 @@ public partial class Startup
 	{
 		static Startup()
 		{
-			Logger.Log(LogLevel.Information, "Elastic.Apm.Profiler.Managed.Loader.Startup: Invoked ");
+			Logger.Log(LogLevel.Information, "Elastic.Apm.Profiler.Managed.Loader.Startup: Invoked. AppDomain: {0}, CLR version: {1}",
+				AppDomain.CurrentDomain.FriendlyName, Environment.Version);
+			var loaderOptimization = ReadEnvironmentVariable("COMPlus_LoaderOptimization");
+			Logger.Log(LogLevel.Debug, "COMPlus_LoaderOptimization={0}", loaderOptimization ?? "(not set)");
+			Logger.Log(LogLevel.Debug, "AppDomain base directory: {0}", AppDomain.CurrentDomain.BaseDirectory);
+			Logger.Log(LogLevel.Debug, "AppDomain shadow copy files: {0}", AppDomain.CurrentDomain.ShadowCopyFiles);
 			Directory = ResolveDirectory();
 
 			try
 			{
 				AppDomain.CurrentDomain.AssemblyResolve += ResolveDependencies;
+				Logger.Log(LogLevel.Debug, "AssemblyResolve event handler registered on AppDomain '{0}'", AppDomain.CurrentDomain.FriendlyName);
 			}
 			catch (Exception e)
 			{
@@ -36,13 +42,76 @@ private static void TryLoadManagedAssembly()
 			try
 			{
 				var version = Assembly.GetExecutingAssembly().GetName().Version;
-				var assembly = Assembly.Load($"Elastic.Apm.Profiler.Managed, Version={version}, Culture=neutral, PublicKeyToken=ae7400d2c189cf22");
+				var assemblyName = $"Elastic.Apm.Profiler.Managed, Version={version}, Culture=neutral, PublicKeyToken=ae7400d2c189cf22";
+
+				Assembly assembly;
+				try
+				{
+					var alreadyLoaded = Array.FindAll(
+						AppDomain.CurrentDomain.GetAssemblies(),
+						a => string.Equals(a.GetName().Name, "Elastic.Apm.Profiler.Managed", StringComparison.OrdinalIgnoreCase));
+					if (alreadyLoaded.Length > 0)
+					{
+						foreach (var loaded in alreadyLoaded)
+							Logger.Log(LogLevel.Warning, "Elastic.Apm.Profiler.Managed already loaded in AppDomain before Assembly.Load: {0} from '{1}'", loaded.FullName, loaded.Location);
+					}
+					else
+						Logger.Log(LogLevel.Debug, "Elastic.Apm.Profiler.Managed not yet present in AppDomain");
+
+					Logger.Log(LogLevel.Debug, "Attempting Assembly.Load for {0}", assemblyName);
+					assembly = Assembly.Load(assemblyName);
+					Logger.Log(LogLevel.Debug, "Assembly.Load succeeded: {0}", assembly?.Location ?? "(null)");
+				}
+				catch (Exception loadEx)
+				{
+					// Assembly.Load can fail on .NET Framework when the CLR's fusion probing finds the
+					// assembly in a path outside the profiler folder (e.g. the application's bin directory
+					// from a previous shadow-copy or partial bind) but cannot satisfy all its dependencies
+					// from that location. In that case AssemblyResolve is never fired. Fall back to
+					// Assembly.LoadFrom with the explicit profiler path, which bypasses fusion probing.
+					WarnIfConflictingAssemblyInAppPath("Elastic.Apm.Profiler.Managed.dll");
+					Logger.Log(LogLevel.Warning, loadEx, "Assembly.Load failed for {0}, falling back to Assembly.LoadFrom from {1}", assemblyName, Directory);
+					var path = System.IO.Path.Combine(Directory, "Elastic.Apm.Profiler.Managed.dll");
+					Logger.Log(LogLevel.Debug, "Assembly.LoadFrom path: {0}, exists: {1}", path, System.IO.File.Exists(path));
+					assembly = Assembly.LoadFrom(path);
+					Logger.Log(LogLevel.Debug, "Assembly.LoadFrom succeeded: {0}", assembly?.Location ?? "(null)");
+					Logger.Log(LogLevel.Warning,
+						"Assembly loaded via LoadFrom fallback (Load context unavailable). "
+						+ "Native profiler ReJIT instrumentation may not activate. "
+						+ "If instrumentation is missing, set COMPlus_LoaderOptimization=1 on the app pool environment variables.");
+				}
+
 				if (assembly == null)
+				{
+					Logger.Log(LogLevel.Error, "Failed to load Elastic.Apm.Profiler.Managed: assembly is null");
 					return;
+				}
+
+				if (!string.IsNullOrEmpty(assembly.Location)
+					&& !assembly.Location.StartsWith(Directory, StringComparison.OrdinalIgnoreCase))
+				{
+					Logger.Log(LogLevel.Warning,
+						"Elastic.Apm.Profiler.Managed loaded from unexpected location: {0}. Expected location under profiler directory: {1}. This may indicate a version mismatch.",
+						assembly.Location, Directory);
+				}
 
 				var type = assembly.GetType("Elastic.Apm.Profiler.Managed.AutoInstrumentation", throwOnError: false);
-				var method = type?.GetRuntimeMethod("Initialize", parameters: Type.EmptyTypes);
-				method?.Invoke(obj: null, parameters: null);
+				if (type == null)
+				{
+					Logger.Log(LogLevel.Error, "Could not find type Elastic.Apm.Profiler.Managed.AutoInstrumentation in {0}", assembly.Location);
+					return;
+				}
+
+				var method = type.GetRuntimeMethod("Initialize", parameters: Type.EmptyTypes);
+				if (method == null)
+				{
+					Logger.Log(LogLevel.Error, "Could not find method AutoInstrumentation.Initialize in {0}", assembly.Location);
+					return;
+				}
+
+				Logger.Log(LogLevel.Debug, "Invoking AutoInstrumentation.Initialize");
+				method.Invoke(obj: null, parameters: null);
+				Logger.Log(LogLevel.Information, "AutoInstrumentation.Initialize completed successfully");
 			}
 			catch (Exception e)
 			{
@@ -52,6 +121,27 @@ private static void TryLoadManagedAssembly()
 
 		internal static string Directory { get; }
 
+		private static void WarnIfConflictingAssemblyInAppPath(string fileName)
+		{
+			var baseDir = AppDomain.CurrentDomain.BaseDirectory;
+			var candidates = new[]
+			{
+				System.IO.Path.Combine(baseDir, fileName),
+				System.IO.Path.Combine(baseDir, "bin", fileName),
+			};
+			foreach (var candidate in candidates)
+			{
+				if (System.IO.File.Exists(candidate))
+				{
+					Logger.Log(LogLevel.Warning,
+						"Conflicting assembly found at {0}. Under MultiDomainHost loader optimization (IIS default), "
+						+ "this causes Assembly.Load to fail without firing AssemblyResolve. "
+						+ "Set COMPlus_LoaderOptimization=1 on the app pool environment variables to resolve.",
+						candidate);
+				}
+			}
+		}
+
 		internal static string ReadEnvironmentVariable(string key)
 		{
 			try

src/profiler/Elastic.Apm.Profiler.Managed/AutoInstrumentation.cs

@@ -43,10 +43,17 @@ public static void Initialize()
 				// was instantiated here.
 				// ReSharper disable once ConvertIfToOrExpression
 				if (System.Web.Hosting.HostingEnvironment.IsHosted)
+				{
+					Logger.Log(LogLevel.Debug,
+						"IIS hosted application detected (HostingEnvironment.IsHosted=true) — skipping agent instantiation. "
+						+ "The agent will be configured by ElasticApmModule; native profiler ReJIT hooks will provide SQL/HTTP instrumentation. "
+						+ "Application: {0}",
+						System.Web.Hosting.HostingEnvironment.ApplicationVirtualPath ?? "(unknown)");
 					skipInstantiation = true;
+				}
 #endif
 				Logger.Log(LogLevel.Debug,
-					"{0}: value of {1}", $"{nameof(AutoInstrumentation)}.{nameof(Initialize)}", skipInstantiation);
+					"{0}: skipInstantiation={1}", $"{nameof(AutoInstrumentation)}.{nameof(Initialize)}", skipInstantiation);
 
 				// ensure global instance is created if it's not already
 				if (!skipInstantiation)