diff --git a/src/Elastic.Apm/Api/Service.cs b/src/Elastic.Apm/Api/Service.cs index 56cc71a3e..af62d263d 100644 --- a/src/Elastic.Apm/Api/Service.cs +++ b/src/Elastic.Apm/Api/Service.cs @@ -103,7 +103,7 @@ static bool CheckForLoadedAssembly(string name) else if (CheckForLoadedAssembly("Elastic.Apm.StartupHook.Loader")) activationMethod = Consts.ActivationMethodStartupHook; - logger.Info()?.Log($"Detected agent activation method: {activationMethod}"); + logger.Info()?.Log("Detected agent activation method: {ActivationMethod}", activationMethod); service.Agent.ActivationMethod = activationMethod; } diff --git a/src/Elastic.Apm/BackendComm/BackendCommUtils.cs b/src/Elastic.Apm/BackendComm/BackendCommUtils.cs index 47da859a2..cb47daa17 100644 --- a/src/Elastic.Apm/BackendComm/BackendCommUtils.cs +++ b/src/Elastic.Apm/BackendComm/BackendCommUtils.cs @@ -221,13 +221,13 @@ private static HttpClientHandler CreateHttpClientHandler(IConfiguration configur logger.Info()?.Log("CreateHttpClientHandler - Setting ServerCertificateCustomValidationCallback"); httpClientHandler.SslProtocols |= SslProtocols.Tls12; - logger.Info()?.Log($"CreateHttpClientHandler - SslProtocols: {httpClientHandler.SslProtocols}"); + logger.Info()?.Log("CreateHttpClientHandler - SslProtocols: {SslProtocols}", httpClientHandler.SslProtocols); #else // We don't set the ServerCertificateCustomValidationCallback on ServicePointManager here as it would // apply to the whole AppDomain and that may not be desired. A consumer can set this themselves if they // need custom validation behaviour. ServicePointManager.SecurityProtocol |= SecurityProtocolType.Tls12; - logger.Info()?.Log($"CreateHttpClientHandler - SslProtocols: {ServicePointManager.SecurityProtocol}"); + logger.Info()?.Log("CreateHttpClientHandler - SslProtocols: {SslProtocols}", ServicePointManager.SecurityProtocol); #endif return httpClientHandler; } diff --git a/src/Elastic.Apm/Config/ConfigurationKeyValue.cs b/src/Elastic.Apm/Config/ConfigurationKeyValue.cs index 70d440f0f..851a8c024 100644 --- a/src/Elastic.Apm/Config/ConfigurationKeyValue.cs +++ b/src/Elastic.Apm/Config/ConfigurationKeyValue.cs @@ -48,6 +48,10 @@ private string ValueForLogging } + + public void Log(T state, Action logCallback) => + logCallback(state, $"{Type,13}", Option.ToNormalizedName(), ValueForLogging, ReadFrom); + public override string ToString() => $"{Type,13}->{Option.ToNormalizedName()}: '{ValueForLogging}' ({ReadFrom})"; } diff --git a/src/Elastic.Apm/Config/ConfigurationLogger.cs b/src/Elastic.Apm/Config/ConfigurationLogger.cs index 8699c79e8..159b091cd 100644 --- a/src/Elastic.Apm/Config/ConfigurationLogger.cs +++ b/src/Elastic.Apm/Config/ConfigurationLogger.cs @@ -65,15 +65,15 @@ public static void PrintAgentLogPreamble(IApmLogger logger, IConfigurationReader var info = logger.Info()!.Value; var version = Assembly.GetExecutingAssembly().GetCustomAttribute().InformationalVersion; info.Log("********************************************************************************"); - info.Log($"Elastic APM .NET Agent, version: {version}"); - info.Log($"Process ID: {Process.GetCurrentProcess().Id}"); - info.Log($"Process Name: {Process.GetCurrentProcess().ProcessName}"); - info.Log($"Command line arguments: '{string.Join(", ", System.Environment.GetCommandLineArgs())}'"); - info.Log($"Operating System: {RuntimeInformation.OSDescription}"); - info.Log($"CPU architecture: {RuntimeInformation.OSArchitecture}"); - info.Log($"Host: {System.Environment.MachineName}"); - info.Log($"Time zone: {TimeZoneInfo.Local}"); - info.Log($"Runtime: {RuntimeInformation.FrameworkDescription}"); + info.Log("Elastic APM .NET Agent, version: {ApmAgentVersion}", version); + 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("Operating System: {OSDescription}", RuntimeInformation.OSDescription); + info.Log("CPU architecture: {OSArchitecture}", RuntimeInformation.OSArchitecture); + info.Log("Host: {HostName}", System.Environment.MachineName); + info.Log("Time zone: {TimeZone}", TimeZoneInfo.Local); + info.Log("Runtime: {RunTime}", RuntimeInformation.FrameworkDescription); PrintAgentConfiguration(logger, configurationReader); } catch (Exception e) @@ -90,7 +90,8 @@ public static void PrintAgentConfiguration(IApmLogger logger, IConfigurationRead { var info = logger.Info()!.Value; info.Log("********************************************************************************"); - info.Log($"Agent Configuration (via '{configurationReader.Description ?? configurationReader.GetType().ToString()}'):"); + info.Log("Agent Configuration (via '{ConfigurationProvider}'):" + , configurationReader.Description ?? configurationReader.GetType().ToString()); var activeConfiguration = OptionLoggingInstructions .Select(instruction => @@ -107,7 +108,10 @@ public static void PrintAgentConfiguration(IApmLogger logger, IConfigurationRead .ThenBy(t => string.IsNullOrEmpty(t.configuration.Value) ? 1 : 0); foreach (var (_, configuration) in activeConfiguration) - info.Log($"{configuration}"); + { + configuration.Log(info, static (l, type, name, value, origin) => + l.Log("{Type}->{Name}: '{Value}' ({Origin})", type, name, value, origin)); + } info.Log("********************************************************************************"); } diff --git a/src/Elastic.Apm/Features/AgentFeatures.cs b/src/Elastic.Apm/Features/AgentFeatures.cs index 5879e3b16..baa6794af 100644 --- a/src/Elastic.Apm/Features/AgentFeatures.cs +++ b/src/Elastic.Apm/Features/AgentFeatures.cs @@ -31,7 +31,8 @@ internal AgentFeatures(IApmLogger logger, string name, AgentFeature featureMask) internal bool Check(AgentFeature agentFeature) { var enabled = (_enabledFeatures & agentFeature) == agentFeature; - _logger?.Trace()?.Log($"[Agent Feature] '{agentFeature}' enabled: {enabled.ToString(DateTimeFormatInfo.InvariantInfo)}"); + _logger?.Trace()?.Log("[Agent Feature] '{AgentFeature}' enabled: {AgentFeatureEnabled}" + , agentFeature, enabled.ToString(DateTimeFormatInfo.InvariantInfo)); return enabled; } diff --git a/src/Elastic.Apm/Features/AgentFeaturesProvider.cs b/src/Elastic.Apm/Features/AgentFeaturesProvider.cs index 16247a23e..2b60e233a 100644 --- a/src/Elastic.Apm/Features/AgentFeaturesProvider.cs +++ b/src/Elastic.Apm/Features/AgentFeaturesProvider.cs @@ -24,7 +24,7 @@ internal static AgentFeatures Get(IApmLogger logger, IEnvironmentVariables envir AgentFeatures = new AzureFunctionsAgentFeatures(logger); else AgentFeatures = new DefaultAgentFeatures(logger); - logger?.Trace()?.Log($"[Agent Features] Using '{AgentFeatures.Name}' feature set]"); + logger?.Trace()?.Log("[Agent Features] Using '{AgentFeaturesName}' feature set]", AgentFeatures.Name); } return AgentFeatures; } diff --git a/src/Elastic.Apm/OpenTelemetry/ElasticActivityListener.cs b/src/Elastic.Apm/OpenTelemetry/ElasticActivityListener.cs index f6e745b33..4751834a0 100644 --- a/src/Elastic.Apm/OpenTelemetry/ElasticActivityListener.cs +++ b/src/Elastic.Apm/OpenTelemetry/ElasticActivityListener.cs @@ -64,11 +64,12 @@ internal void Start(Tracer tracerInternal) private Action ActivityStarted => activity => { - _logger.Trace()?.Log($"ActivityStarted: name:{activity.DisplayName} id:{activity.Id} traceId:{activity.TraceId}"); - if (KnownListeners.KnownListenersList.Contains(activity.DisplayName)) return; + _logger.Trace()?.Log("ActivityStarted: name:{DisplayName} id:{ActivityId} traceId:{TraceId}", + activity.DisplayName, activity.Id, activity.TraceId); + var spanLinks = new List(activity.Links.Count()); if (activity.Links.Any()) { @@ -146,7 +147,8 @@ private void CreateSpanForActivity(Activity activity, long timestamp, List diff --git a/src/azure/Elastic.Apm.Azure.Functions/AzureFunctionsContext.cs b/src/azure/Elastic.Apm.Azure.Functions/AzureFunctionsContext.cs index d7cfb3694..2ed9629f0 100644 --- a/src/azure/Elastic.Apm.Azure.Functions/AzureFunctionsContext.cs +++ b/src/azure/Elastic.Apm.Azure.Functions/AzureFunctionsContext.cs @@ -21,7 +21,7 @@ internal AzureFunctionsContext(string loggerScopeName) UpdateServiceInformation(Agent.Instance.Service); FaasIdPrefix = $"/subscriptions/{MetaData.SubscriptionId}/resourceGroups/{MetaData.WebsiteResourceGroup}/providers/Microsoft.Web/sites/{MetaData.WebsiteSiteName}/functions/"; - Logger.Trace()?.Log($"FaasIdPrefix: {FaasIdPrefix}"); + Logger.Trace()?.Log("FaasIdPrefix: {FaasIdPrefix}", FaasIdPrefix); } internal IApmLogger Logger { get; } diff --git a/src/azure/Elastic.Apm.Azure.Functions/AzureFunctionsDiagnosticListener.cs b/src/azure/Elastic.Apm.Azure.Functions/AzureFunctionsDiagnosticListener.cs index 21a2e8620..9f89d4928 100644 --- a/src/azure/Elastic.Apm.Azure.Functions/AzureFunctionsDiagnosticListener.cs +++ b/src/azure/Elastic.Apm.Azure.Functions/AzureFunctionsDiagnosticListener.cs @@ -27,7 +27,7 @@ public AzureFunctionsDiagnosticListener(ApmAgent agent) : base(agent) { } protected override void HandleOnNext(KeyValuePair kv) { - Context.Logger.Trace()?.Log($"'{nameof(AzureFunctionsDiagnosticListener)}.{nameof(HandleOnNext)}': {kv.Key}"); + Context.Logger.Trace()?.Log($"'{nameof(AzureFunctionsDiagnosticListener)}.{nameof(HandleOnNext)}': {{DiagnosticsEventName}}", kv.Key); if (kv.Key == "Microsoft.AspNetCore.Hosting.HttpRequestIn.Start") HandleRequestInStart(kv.Value as DefaultHttpContext); else if (kv.Key == "Microsoft.AspNetCore.Hosting.HttpRequestIn.Stop") diff --git a/src/integrations/Elastic.Apm.AspNetFullFramework/ElasticApmModule.cs b/src/integrations/Elastic.Apm.AspNetFullFramework/ElasticApmModule.cs index 8137c2452..95f3bcaa2 100644 --- a/src/integrations/Elastic.Apm.AspNetFullFramework/ElasticApmModule.cs +++ b/src/integrations/Elastic.Apm.AspNetFullFramework/ElasticApmModule.cs @@ -156,12 +156,16 @@ private void RestoreContextIfNeeded(HttpContextBase context) if (Agent.Instance == null) { - _logger.Trace()?.Log($"Agent.Instance is null during {nameof(OnExecuteRequestStep)}:{EventName()}. url: {urlPath}"); + _logger.Trace()? + .Log("Agent.Instance is null during {RequestNotification}. url: {{UrlPath}}", + $"{nameof(OnExecuteRequestStep)}:{EventName()}", urlPath); return; } if (Agent.Instance.Tracer == null) { - _logger.Trace()?.Log($"Agent.Instance.Tracer is null during {nameof(OnExecuteRequestStep)}:{EventName()}. url: {urlPath}"); + _logger.Trace()? + .Log("Agent.Instance.Tracer is null during {RequestNotification}. url: {{UrlPath}}", + $"{nameof(OnExecuteRequestStep)}:{EventName()}", urlPath); return; } var transaction = Agent.Instance?.Tracer?.CurrentTransaction; @@ -176,14 +180,17 @@ private void RestoreContextIfNeeded(HttpContextBase context) var spanInApplicationInstance = context.Items[HttpContextCurrentExecutionSegmentsContainer.CurrentSpanKey] is not null; _logger.Trace()? - .Log($"{nameof(ITracer.CurrentTransaction)} is null during {nameof(OnExecuteRequestStep)}:{EventName()}. url: {urlPath} " - + $"(HttpContext.Current Span: {spanInCurrent}, Transaction: {transactionInCurrent})" - + $"(ApplicationContext Span: {spanInApplicationInstance}, Transaction: {transactionInApplicationInstance})"); + .Log($"{nameof(ITracer.CurrentTransaction)} is null during {{RequestNotification}}. url: {{UrlPath}}" + + "(HttpContext.Current Span: {HttpContextCurrentHasSpan}, Transaction: {HttpContextCurrenHasTransaction})" + + "(ApplicationContext Span: {ApplicationContextHasSpan}, Transaction: {ApplicationContextHasTransaction})", + $"{nameof(OnExecuteRequestStep)}:{EventName()}", urlPath, spanInCurrent, transactionInCurrent, spanInApplicationInstance, transactionInApplicationInstance + ); if (HttpContext.Current == null) { _logger.Trace()? - .Log($"HttpContext.Current is null during {nameof(OnExecuteRequestStep)}:{EventName()}. Unable to attempt to restore transaction. url: {urlPath}"); + .Log("HttpContext.Current is null during {RequestNotification}. Unable to attempt to restore transaction. url: {UrlPath}", + $"{nameof(OnExecuteRequestStep)}:{EventName()}", urlPath); return; } @@ -191,13 +198,15 @@ private void RestoreContextIfNeeded(HttpContextBase context) { HttpContext.Current.Items[HttpContextCurrentExecutionSegmentsContainer.CurrentTransactionKey] = context.Items[HttpContextCurrentExecutionSegmentsContainer.CurrentTransactionKey]; - _logger.Trace()?.Log($"Restored transaction to HttpContext.Current.Items {nameof(OnExecuteRequestStep)}:{EventName()}. url: {urlPath}"); + _logger.Trace()?.Log("Restored transaction to HttpContext.Current.Items {RequestNotification}. url: {UrlPath}", + $"{nameof(OnExecuteRequestStep)}:{EventName()}", urlPath); } if (!spanInCurrent && spanInApplicationInstance) { HttpContext.Current.Items[HttpContextCurrentExecutionSegmentsContainer.CurrentSpanKey] = context.Items[HttpContextCurrentExecutionSegmentsContainer.CurrentSpanKey]; - _logger.Trace()?.Log($"Restored span to HttpContext.Current.Items {nameof(OnExecuteRequestStep)}:{EventName()}. url: {urlPath}"); + _logger.Trace()?.Log("Restored span to HttpContext.Current.Items {RequestNotification}:{EventName()}. url: {UrlPath}", + $"{nameof(OnExecuteRequestStep)}:{EventName()}", urlPath); } }