Skip to content

Commit 0031700

Browse files
chynesNRchynesNR
authored
feat: Use structured logging for internal logs (#1903)
* First pass at internal structured logging * Second pass * PR feedback * Strange compile error * Trying to fix GHA error * Revert back to original log level
1 parent 213ff9e commit 0031700

File tree

80 files changed

+334
-553
lines changed

Some content is hidden

Large Commits have some content hidden by default. Use the searchbox below for content that may be hidden.

80 files changed

+334
-553
lines changed

‎src/Agent/NewRelic/Agent/Core/Agent.cs

+3-3
Original file line numberDiff line numberDiff line change
@@ -213,7 +213,7 @@ bool ShouldRunExplain()
213213
var vendorValidationResult = vendorValidateShouldExplain();
214214
if (!vendorValidationResult.IsValid)
215215
{
216-
Log.DebugFormat("Failed vendor condition for executing explain plan: {0}", vendorValidationResult.ValidationMessage);
216+
Log.Debug("Failed vendor condition for executing explain plan: {0}", vendorValidationResult.ValidationMessage);
217217
return false;
218218
}
219219
}
@@ -281,7 +281,7 @@ public void HandleWrapperException(Exception exception)
281281
return;
282282
}
283283

284-
Log.Error($"An exception occurred in a wrapper: {exception}");
284+
Log.Error(exception, "An exception occurred in a wrapper");
285285
}
286286

287287
#endregion Error handling
@@ -336,7 +336,7 @@ public Stream TryGetStreamInjector(Stream stream, Encoding encoding, string cont
336336
}
337337
catch (Exception ex)
338338
{
339-
Log.Error($"RUM: Failed to build Browser Monitoring agent script: {ex}");
339+
Log.Error(ex, "RUM: Failed to build Browser Monitoring agent script");
340340
{
341341
return null;
342342
}

‎src/Agent/NewRelic/Agent/Core/AgentHealth/AgentHealthReporter.cs

+6-18
Original file line numberDiff line numberDiff line change
@@ -26,7 +26,7 @@ public class AgentHealthReporter : ConfigurationBasedService, IAgentHealthReport
2626

2727
private readonly IMetricBuilder _metricBuilder;
2828
private readonly IScheduler _scheduler;
29-
private readonly IList<RecurringLogData> _recurringLogDatas = new ConcurrentList<RecurringLogData>();
29+
private readonly IList<string> _recurringLogData = new ConcurrentList<string>();
3030
private readonly IDictionary<AgentHealthEvent, InterlockedCounter> _agentHealthEventCounters = new Dictionary<AgentHealthEvent, InterlockedCounter>();
3131
private readonly ConcurrentDictionary<string, InterlockedCounter> _logLinesCountByLevel = new ConcurrentDictionary<string, InterlockedCounter>();
3232
private readonly ConcurrentDictionary<string, InterlockedCounter> _logDeniedCountByLevel = new ConcurrentDictionary<string, InterlockedCounter>();
@@ -63,9 +63,9 @@ public override void Dispose()
6363

6464
private void LogPeriodicReport()
6565
{
66-
foreach (var data in _recurringLogDatas)
66+
foreach (var logMessage in _recurringLogData)
6767
{
68-
data?.LogAction(data.Message);
68+
Log.Debug(logMessage);
6969
}
7070

7171
List<string> events = new List<string>();
@@ -252,7 +252,7 @@ public void ReportWrapperShutdown(IWrapper wrapper, Method method)
252252
}
253253

254254
Log.Error($"Wrapper {wrapperName} is being disabled for {method.MethodName} due to too many consecutive exceptions. All other methods using this wrapper will continue to be instrumented. This will reduce the functionality of the agent until the agent is restarted.");
255-
_recurringLogDatas.Add(new RecurringLogData(Log.Debug, $"Wrapper {wrapperName} was disabled for {method.MethodName} at {DateTime.Now} due to too many consecutive exceptions. All other methods using this wrapper will continue to be instrumented. This will reduce the functionality of the agent until the agent is restarted."));
255+
_recurringLogData.Add($"Wrapper {wrapperName} was disabled for {method.MethodName} at {DateTime.Now} due to too many consecutive exceptions. All other methods using this wrapper will continue to be instrumented. This will reduce the functionality of the agent until the agent is restarted.");
256256
}
257257

258258
public void ReportIfHostIsLinuxOs()
@@ -714,7 +714,7 @@ private void TrySend(MetricWireModel metric)
714714

715715
if (_publishMetricDelegate == null)
716716
{
717-
Log.WarnFormat("No PublishMetricDelegate to flush metric '{0}' through.", metric.MetricName.Name);
717+
Log.Warn("No PublishMetricDelegate to flush metric '{0}' through.", metric.MetricName.Name);
718718
return;
719719
}
720720

@@ -724,7 +724,7 @@ private void TrySend(MetricWireModel metric)
724724
}
725725
catch (Exception ex)
726726
{
727-
Log.Error(ex);
727+
Log.Error(ex, "TrySend() failed");
728728
}
729729
}
730730
private bool TryGetCount(InterlockedCounter counter, out int metricCount)
@@ -811,17 +811,5 @@ protected override void OnConfigurationUpdated(ConfigurationUpdateSource configu
811811
// Some one time metrics are reporting configured values, so we want to re-report them if the configuration changed
812812
_oneTimeMetricsCollected = false;
813813
}
814-
815-
private class RecurringLogData
816-
{
817-
public readonly Action<string> LogAction;
818-
public readonly string Message;
819-
820-
public RecurringLogData(Action<string> logAction, string message)
821-
{
822-
LogAction = logAction;
823-
Message = message;
824-
}
825-
}
826814
}
827815
}

‎src/Agent/NewRelic/Agent/Core/AgentInstallConfiguration.cs

+1-1
Original file line numberDiff line numberDiff line change
@@ -111,7 +111,7 @@ private static string GetAgentVersion()
111111
}
112112
catch (Exception ex)
113113
{
114-
Log.Error($"Failed to determine agent version. {ex}");
114+
Log.Error(ex, "Failed to determine agent version.");
115115
return "?.?.?.?";
116116
}
117117
}

‎src/Agent/NewRelic/Agent/Core/AgentManager.cs

+9-9
Original file line numberDiff line numberDiff line change
@@ -55,7 +55,7 @@ protected override IAgentManager CreateInstance()
5555
{
5656
try
5757
{
58-
Log.Error($"There was an error initializing the agent: {exception}");
58+
Log.Error(exception, "There was an error initializing the agent");
5959
return DisabledAgentManager;
6060
}
6161
catch
@@ -182,7 +182,7 @@ private void Initialize()
182182

183183
private void LogInitialized()
184184
{
185-
Log.InfoFormat("The New Relic .NET Agent v{0} started (pid {1}) on app domain '{2}'", AgentInstallConfiguration.AgentVersion, AgentInstallConfiguration.ProcessId, AgentInstallConfiguration.AppDomainAppVirtualPath ?? AgentInstallConfiguration.AppDomainName);
185+
Log.Info("The New Relic .NET Agent v{0} started (pid {1}) on app domain '{2}'", AgentInstallConfiguration.AgentVersion, AgentInstallConfiguration.ProcessId, AgentInstallConfiguration.AppDomainAppVirtualPath ?? AgentInstallConfiguration.AppDomainName);
186186
//Log here for debugging configuration issues
187187
if (Log.IsDebugEnabled)
188188
{
@@ -270,15 +270,15 @@ private void LogInitialized()
270270
{
271271
if (!string.IsNullOrEmpty(System.Environment.GetEnvironmentVariable(ev)))
272272
{
273-
Log.DebugFormat("Environment Variable {0} value: {1}", ev, System.Environment.GetEnvironmentVariable(ev));
273+
Log.Debug("Environment Variable {0} value: {1}", ev, System.Environment.GetEnvironmentVariable(ev));
274274
}
275275
}
276276

277277
foreach (var evs in environmentVariablesSensitive)
278278
{
279279
if (!string.IsNullOrEmpty(System.Environment.GetEnvironmentVariable(evs)))
280280
{
281-
Log.DebugFormat("Environment Variable {0} is configured with a value. Not logging potentially sensitive value", evs);
281+
Log.Debug("Environment Variable {0} is configured with a value. Not logging potentially sensitive value", evs);
282282
}
283283
}
284284

@@ -288,12 +288,12 @@ private void LogInitialized()
288288
#if NETFRAMEWORK
289289
if (NewRelic.Core.DotnetVersion.IsUnsupportedDotnetFrameworkVersion(AgentInstallConfiguration.DotnetFrameworkVersion))
290290
{
291-
Log.WarnFormat("Unsupported installed .NET Framework version {0} dectected. Please use a version of .NET Framework >= 4.6.2.", AgentInstallConfiguration.DotnetFrameworkVersion);
291+
Log.Warn("Unsupported installed .NET Framework version {0} dectected. Please use a version of .NET Framework >= 4.6.2.", AgentInstallConfiguration.DotnetFrameworkVersion);
292292
}
293293
#else
294294
if (NewRelic.Core.DotnetVersion.IsUnsupportedDotnetCoreVersion(AgentInstallConfiguration.DotnetCoreVersion))
295295
{
296-
Log.WarnFormat("Unsupported .NET version {0} detected. Please use a version of .NET >= net6.", AgentInstallConfiguration.DotnetCoreVersion);
296+
Log.Warn("Unsupported .NET version {0} detected. Please use a version of .NET >= net6.", AgentInstallConfiguration.DotnetCoreVersion);
297297
}
298298
#endif
299299
}
@@ -340,7 +340,7 @@ public ITracer GetTracerImpl(string tracerFactoryName, uint tracerArguments, str
340340
}
341341
catch (Exception e)
342342
{
343-
Log.Error($"Tracer invocation error: {e}");
343+
Log.Error(e, "Tracer invocation error");
344344
return null;
345345
}
346346
}
@@ -375,11 +375,11 @@ private void Shutdown(bool cleanShutdown)
375375

376376
Log.Debug("Shutting down public agent services...");
377377
StopServices();
378-
Log.InfoFormat("The New Relic .NET Agent v{0} has shutdown (pid {1}) on app domain '{2}'", AgentInstallConfiguration.AgentVersion, AgentInstallConfiguration.ProcessId, AgentInstallConfiguration.AppDomainAppVirtualPath ?? AgentInstallConfiguration.AppDomainName);
378+
Log.Info("The New Relic .NET Agent v{0} has shutdown (pid {1}) on app domain '{2}'", AgentInstallConfiguration.AgentVersion, AgentInstallConfiguration.ProcessId, AgentInstallConfiguration.AppDomainAppVirtualPath ?? AgentInstallConfiguration.AppDomainName);
379379
}
380380
catch (Exception e)
381381
{
382-
Log.Debug($"Shutdown error: {e}");
382+
Log.Debug(e, "Shutdown error");
383383
}
384384
finally
385385
{

‎src/Agent/NewRelic/Agent/Core/Aggregators/MetricStatsCollectionQueue.cs

+1-1
Original file line numberDiff line numberDiff line change
@@ -66,7 +66,7 @@ private void AddMetricsToCollection(ConcurrentQueue<MetricStatsCollection> stats
6666
}
6767
catch (Exception e)
6868
{
69-
Log.Warn($"Exception dequeueing/creating stats collection: {e}");
69+
Log.Warn(e, "Exception dequeueing/creating stats collection");
7070
}
7171
finally
7272
{

‎src/Agent/NewRelic/Agent/Core/Aggregators/TransactionTraceAggregator.cs

+1-1
Original file line numberDiff line numberDiff line change
@@ -106,7 +106,7 @@ private void LogUnencodedTraceData(IEnumerable<TransactionTraceWireModel> sample
106106
{
107107
if (sample != null)
108108
{
109-
Log.DebugFormat("TransactionTraceData: {0}", SerializeTransactionTraceData(sample));
109+
Log.Debug("TransactionTraceData: {0}", SerializeTransactionTraceData(sample));
110110
}
111111
}
112112
}

‎src/Agent/NewRelic/Agent/Core/Api/AgentApiImplementation.cs

+3-3
Original file line numberDiff line numberDiff line change
@@ -79,7 +79,7 @@ public void InitializePublicAgent(object publicAgent)
7979
{
8080
try
8181
{
82-
Log.Error($"Failed to initialize the Agent API: {ex}");
82+
Log.Error(ex, "Failed to initialize the Agent API");
8383
}
8484
catch (Exception)//Swallow the error
8585
{
@@ -728,7 +728,7 @@ public IEnumerable<KeyValuePair<string, string>> GetRequestMetadata()
728728
{
729729
if (_configurationService.Configuration.DistributedTracingEnabled)
730730
{
731-
Log.FinestFormat(DistributedTracingIsEnabledIgnoringCall, nameof(GetRequestMetadata));
731+
Log.Finest(DistributedTracingIsEnabledIgnoringCall, nameof(GetRequestMetadata));
732732
return Enumerable.Empty<KeyValuePair<string, string>>();
733733
}
734734

@@ -742,7 +742,7 @@ public IEnumerable<KeyValuePair<string, string>> GetResponseMetadata()
742742
{
743743
if (_configurationService.Configuration.DistributedTracingEnabled)
744744
{
745-
Log.FinestFormat(DistributedTracingIsEnabledIgnoringCall, nameof(GetResponseMetadata));
745+
Log.Finest(DistributedTracingIsEnabledIgnoringCall, nameof(GetResponseMetadata));
746746
return Enumerable.Empty<KeyValuePair<string, string>>();
747747
}
748748

‎src/Agent/NewRelic/Agent/Core/Api/AgentBridgeApi.cs

+3-3
Original file line numberDiff line numberDiff line change
@@ -40,7 +40,7 @@ public TransactionBridgeApi CurrentTransaction
4040
{
4141
try
4242
{
43-
Log.ErrorFormat("Failed to get CurrentTransaction: {0}", ex);
43+
Log.Error(ex, "Failed to get CurrentTransaction");
4444
}
4545
catch (Exception)
4646
{
@@ -67,7 +67,7 @@ public object TraceMetadata
6767
{
6868
try
6969
{
70-
Log.ErrorFormat("Failed to get TraceMetadata: {0}", ex);
70+
Log.Error(ex, "Failed to get TraceMetadata");
7171
}
7272
catch (Exception)
7373
{
@@ -93,7 +93,7 @@ public Dictionary<string, string> GetLinkingMetadata()
9393
{
9494
try
9595
{
96-
Log.ErrorFormat("Error in GetLinkingMetadata: {0}", ex);
96+
Log.Error(ex, "Error in GetLinkingMetadata");
9797
}
9898
catch (Exception)
9999
{

‎src/Agent/NewRelic/Agent/Core/Api/DistributedTraceApiModel.cs

+1-1
Original file line numberDiff line numberDiff line change
@@ -35,7 +35,7 @@ string DecodePayload()
3535
{
3636
try
3737
{
38-
Log.ErrorFormat("Failed to get DistributedTraceApiModel.Text: {0}", ex);
38+
Log.Error(ex, "Failed to get DistributedTraceApiModel.Text");
3939
}
4040
catch (Exception)
4141
{

‎src/Agent/NewRelic/Agent/Core/Api/SpanBridgeApi.cs

+2-2
Original file line numberDiff line numberDiff line change
@@ -39,7 +39,7 @@ public object AddCustomAttribute(string key, object value)
3939
{
4040
try
4141
{
42-
Log.Error($"Error in AddCustomAttribute: {ex}");
42+
Log.Error(ex, "Error in AddCustomAttribute");
4343
}
4444
catch (Exception)
4545
{
@@ -62,7 +62,7 @@ public object SetName(string name)
6262
{
6363
try
6464
{
65-
Log.Error($"Error in SetName: {ex}");
65+
Log.Error(ex, "Error in SetName");
6666
}
6767
catch (Exception)
6868
{

‎src/Agent/NewRelic/Agent/Core/Api/TransactionBridgeApi.cs

+5-5
Original file line numberDiff line numberDiff line change
@@ -79,7 +79,7 @@ public void InsertDistributedTraceHeaders<T>(T carrier, Action<T, string, string
7979
{
8080
try
8181
{
82-
Log.ErrorFormat("Error in InsertDistributedTraceHeaders<T>(T, Action<T, string, string>): {0}", ex);
82+
Log.Error(ex, "Error in InsertDistributedTraceHeaders<T>(T, Action<T, string, string>)");
8383
}
8484
catch (Exception)
8585
{
@@ -102,7 +102,7 @@ public void AcceptDistributedTraceHeaders<T>(T carrier, Func<T, string, IEnumera
102102
{
103103
try
104104
{
105-
Log.ErrorFormat("Error in AcceptDistributedTraceHeaders<T>(T, Func<T, string, IEnumerable<string>>, TransportType): {0}", ex);
105+
Log.Error(ex, "Error in AcceptDistributedTraceHeaders<T>(T, Func<T, string, IEnumerable<string>>, TransportType)");
106106
}
107107
catch (Exception)
108108
{
@@ -138,7 +138,7 @@ public object AddCustomAttribute(string key, object value)
138138
{
139139
try
140140
{
141-
Log.Error($"Error in AddCustomAttribute: {ex}");
141+
Log.Error(ex, "Error in AddCustomAttribute");
142142
}
143143
catch (Exception)
144144
{
@@ -167,7 +167,7 @@ public SpanBridgeApi CurrentSpan
167167
{
168168
try
169169
{
170-
Log.ErrorFormat("Failed to get CurrentSpan: {0}", ex);
170+
Log.Error(ex, "Failed to get CurrentSpan");
171171
}
172172
catch (Exception)
173173
{
@@ -195,7 +195,7 @@ public void SetUserId(string userid)
195195
{
196196
try
197197
{
198-
Log.Error($"Error in SetUserId: {ex}");
198+
Log.Error(ex, "Error in SetUserId");
199199
}
200200
catch (Exception)
201201
{

‎src/Agent/NewRelic/Agent/Core/Attributes/AttributeValueCollection.cs

+1-1
Original file line numberDiff line numberDiff line change
@@ -286,7 +286,7 @@ public void MakeImmutable()
286286
}
287287
catch (Exception ex)
288288
{
289-
Log.Finest($"{attribVal.AttributeDefinition.Classification} Attribute '{attribVal.AttributeDefinition.Name}' was not recorded - exception occurred while resolving value (lazy) - {ex}");
289+
Log.Finest(ex, "{attribVal.AttributeDefinition.Classification} Attribute '{attribVal.AttributeDefinition.Name}' was not recorded - exception occurred while resolving value (lazy)");
290290
itemsToRemove.Add(attribVal);
291291
}
292292
}

‎src/Agent/NewRelic/Agent/Core/BrowserMonitoring/BrowserMonitoringPrereqChecker.cs

+2-2
Original file line numberDiff line numberDiff line change
@@ -82,7 +82,7 @@ private static bool IsHtmlContent(string contentType)
8282
}
8383
catch (Exception ex)
8484
{
85-
Log.Debug($"Unable to parse content type: {ex}");
85+
Log.Debug(ex, "Unable to parse content type");
8686
return false;
8787
}
8888
}
@@ -134,7 +134,7 @@ private static bool IsMatch(string path, Regex regex)
134134
}
135135
catch (Exception e)
136136
{
137-
Log.Error($"Exception attempting to validate request path for Browser Instrumentation blacklisting: {e}");
137+
Log.Error(e, "Exception attempting to validate request path for Browser Instrumentation blacklisting");
138138
return false;
139139
}
140140
}

‎src/Agent/NewRelic/Agent/Core/BrowserMonitoring/BrowserMonitoringStreamInjector.cs

+1-1
Original file line numberDiff line numberDiff line change
@@ -105,7 +105,7 @@ private Action<byte[], int, int> GetInjectingStreamWriter(Encoding contentEncodi
105105
}
106106
catch (Exception exception)
107107
{
108-
Log.Error($"Failed to inject JavaScript agent into response stream: {exception}");
108+
Log.Error(exception, "Failed to inject JavaScript agent into response stream");
109109
scriptInjected = false;
110110
buffer = originalBuffer;
111111
offset = originalOffset;

‎src/Agent/NewRelic/Agent/Core/CallStack/CallStackManager.cs

+2-2
Original file line numberDiff line numberDiff line change
@@ -61,14 +61,14 @@ private static ICallStackManagerFactory CreateFactory(IEnumerable<IContextStorag
6161
var asyncLocalFactory = listOfFactories.FirstOrDefault(f => f.Type == ContextStorageType.AsyncLocal);
6262
if (asyncLocalFactory != null)
6363
{
64-
Log.DebugFormat("Using async storage {0} for call stack with AsyncCallStackManagerFactory", asyncLocalFactory.GetType().FullName);
64+
Log.Debug("Using async storage {0} for call stack with AsyncCallStackManagerFactory", asyncLocalFactory.GetType().FullName);
6565
return new AsyncCallStackManagerFactory(asyncLocalFactory);
6666
}
6767

6868
var callContextLogicalDataFactory = listOfFactories.FirstOrDefault(f => f.Type == ContextStorageType.CallContextLogicalData);
6969
if (callContextLogicalDataFactory != null)
7070
{
71-
Log.DebugFormat("Using async storage {0} for call stack with AsyncCallStackManagerFactory", callContextLogicalDataFactory.GetType().FullName);
71+
Log.Debug("Using async storage {0} for call stack with AsyncCallStackManagerFactory", callContextLogicalDataFactory.GetType().FullName);
7272
return new AsyncCallStackManagerFactory(callContextLogicalDataFactory);
7373
}
7474

‎src/Agent/NewRelic/Agent/Core/Commands/InstrumentationUpdateCommand.cs

+1-1
Original file line numberDiff line numberDiff line change
@@ -52,7 +52,7 @@ private string InstrumentationUpdate(IDictionary<string, object> arguments)
5252
}
5353
catch (Exception e)
5454
{
55-
Log.Error(e);
55+
Log.Error(e, "The instrumentation update was malformed");
5656
return "The instrumentation update was malformed";
5757
}
5858
}

‎src/Agent/NewRelic/Agent/Core/Commands/StopThreadProfilerCommand.cs

+1-1
Original file line numberDiff line numberDiff line change
@@ -48,7 +48,7 @@ private string StopThreadProfilingSessions(IDictionary<string, object> arguments
4848
}
4949
catch (InvalidProfileIdException e)
5050
{
51-
Log.Error(e.Message);
51+
Log.Error(e, "StopThreadProfilingSessions() failed");
5252
return e.Message;
5353
}
5454

0 commit comments

Comments
 (0)