Skip to content

Commit bfa45d0

Browse files
JamesNKJamesNK
authored
Add log category name to structured logs (#1214)
1 parent a3ed2b5 commit bfa45d0

File tree

7 files changed

+77
-25
lines changed

7 files changed

+77
-25
lines changed

‎src/Aspire.Dashboard/Model/Otlp/LogFilter.cs‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -18,7 +18,7 @@ public class LogFilter
1818

1919
public static List<string> GetAllPropertyNames(List<string> propertyKeys)
2020
{
21-
var result = new List<string> { "Message", "Application", "TraceId", "SpanId", "OriginalFormat" };
21+
var result = new List<string> { "Message", "Category", "Application", "TraceId", "SpanId", "OriginalFormat" };
2222
result.AddRange(propertyKeys);
2323
return result;
2424
}
@@ -88,6 +88,7 @@ private static Func<double, double, bool> ConditionToFuncNumber(FilterCondition
8888
"TraceId" => x.TraceId,
8989
"SpanId" => x.SpanId,
9090
"OriginalFormat" => x.OriginalFormat,
91+
"Category" => x.Scope.ScopeName,
9192
_ => x.Properties.GetValue(Field)
9293
};
9394
}

‎src/Aspire.Dashboard/Otlp/Model/OtlpLogEntry.cs‎

Lines changed: 8 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -19,8 +19,9 @@ public class OtlpLogEntry
1919
public string TraceId { get; }
2020
public string? OriginalFormat { get; }
2121
public OtlpApplication Application { get; }
22+
public OtlpScope Scope { get; }
2223

23-
public OtlpLogEntry(LogRecord record, OtlpApplication logApp)
24+
public OtlpLogEntry(LogRecord record, OtlpApplication logApp, OtlpScope scope)
2425
{
2526
var properties = new List<KeyValuePair<string, string>>();
2627
foreach (var kv in record.Attributes)
@@ -49,6 +50,7 @@ public OtlpLogEntry(LogRecord record, OtlpApplication logApp)
4950
SpanId = record.SpanId.ToHexString();
5051
TraceId = record.TraceId.ToHexString();
5152
Application = logApp;
53+
Scope = scope;
5254
}
5355

5456
private static LogLevel MapSeverity(SeverityNumber severityNumber) => severityNumber switch
@@ -82,13 +84,12 @@ public OtlpLogEntry(LogRecord record, OtlpApplication logApp)
8284

8385
public Dictionary<string, string> AllProperties()
8486
{
85-
var props = new Dictionary<string, string>
86-
{
87-
{ "Application", Application.ApplicationName },
88-
{ "Level", Severity.ToString() },
89-
{ "Message", Message }
90-
};
87+
var props = new Dictionary<string, string>();
9188

89+
AddOptionalValue("Application", Application.ApplicationName, props);
90+
AddOptionalValue("Category", Scope.ScopeName, props);
91+
AddOptionalValue("Level", Severity.ToString(), props);
92+
AddOptionalValue("Message", Message, props);
9293
AddOptionalValue("TraceId", TraceId, props);
9394
AddOptionalValue("SpanId", SpanId, props);
9495
AddOptionalValue("OriginalFormat", OriginalFormat, props);

‎src/Aspire.Dashboard/Otlp/Model/OtlpTraceScope.cs‎ renamed to ‎src/Aspire.Dashboard/Otlp/Model/OtlpScope.cs‎

Lines changed: 11 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -8,16 +8,25 @@ namespace Aspire.Dashboard.Otlp.Model;
88
/// <summary>
99
/// The Scope of a TraceSource, maps to the name of the ActivitySource in .NET
1010
/// </summary>
11-
public class OtlpTraceScope
11+
public class OtlpScope
1212
{
13+
public static readonly OtlpScope Empty = new OtlpScope();
14+
1315
public string ScopeName { get; }
1416
public string Version { get; }
1517

1618
public KeyValuePair<string, string>[] Properties { get; }
1719

1820
public string ServiceProperties => Properties.ConcatProperties();
1921

20-
public OtlpTraceScope(InstrumentationScope scope)
22+
private OtlpScope()
23+
{
24+
ScopeName = string.Empty;
25+
Properties = Array.Empty<KeyValuePair<string, string>>();
26+
Version = string.Empty;
27+
}
28+
29+
public OtlpScope(InstrumentationScope scope)
2130
{
2231
ScopeName = scope.Name;
2332

‎src/Aspire.Dashboard/Otlp/Model/OtlpTrace.cs‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -35,7 +35,7 @@ public TimeSpan Duration
3535

3636
public List<OtlpSpan> Spans { get; } = new List<OtlpSpan>();
3737

38-
public OtlpTraceScope TraceScope { get; }
38+
public OtlpScope TraceScope { get; }
3939

4040
public int CalculateDepth(OtlpSpan span)
4141
{
@@ -93,7 +93,7 @@ private void AssertSpanOrder()
9393
}
9494
}
9595

96-
public OtlpTrace(ReadOnlyMemory<byte> traceId, OtlpTraceScope traceScope)
96+
public OtlpTrace(ReadOnlyMemory<byte> traceId, OtlpScope traceScope)
9797
{
9898
Key = traceId;
9999
TraceId = OtlpHelpers.ToHexString(traceId);

‎src/Aspire.Dashboard/Otlp/Storage/TelemetryRepository.cs‎

Lines changed: 31 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -31,12 +31,13 @@ public class TelemetryRepository
3131
private readonly ConcurrentDictionary<string, OtlpApplication> _applications = new();
3232

3333
private readonly ReaderWriterLockSlim _logsLock = new();
34+
private readonly Dictionary<string, OtlpScope> _logScopes = new();
3435
private readonly CircularBuffer<OtlpLogEntry> _logs;
3536
private readonly HashSet<(OtlpApplication Application, string PropertyKey)> _logPropertyKeys = new();
3637
private readonly Dictionary<OtlpApplication, int> _applicationUnviewedErrorLogs = new();
3738

3839
private readonly ReaderWriterLockSlim _tracesLock = new();
39-
private readonly Dictionary<string, OtlpTraceScope> _traceScopes = new();
40+
private readonly Dictionary<string, OtlpScope> _traceScopes = new();
4041
private readonly CircularBuffer<OtlpTrace> _traces;
4142

4243
public TelemetryRepository(IConfiguration config, ILoggerFactory loggerFactory)
@@ -266,14 +267,31 @@ public void AddLogsCore(AddContext context, OtlpApplication application, Repeate
266267
{
267268
foreach (var sl in scopeLogs)
268269
{
269-
// Instrumentation Scope isn't commonly used for logs.
270-
// Skip it for now until there is feedback that it has useful information.
270+
OtlpScope? scope;
271+
try
272+
{
273+
// The instrumentation scope information for the spans in this message.
274+
// Semantically when InstrumentationScope isn't set, it is equivalent with
275+
// an empty instrumentation scope name (unknown).
276+
var name = sl.Scope?.Name ?? string.Empty;
277+
if (!_logScopes.TryGetValue(name, out scope))
278+
{
279+
scope = (sl.Scope != null) ? new OtlpScope(sl.Scope) : OtlpScope.Empty;
280+
_logScopes.Add(name, scope);
281+
}
282+
}
283+
catch (Exception ex)
284+
{
285+
context.FailureCount += sl.LogRecords.Count;
286+
_logger.LogInformation(ex, "Error adding scope.");
287+
continue;
288+
}
271289

272290
foreach (var record in sl.LogRecords)
273291
{
274292
try
275293
{
276-
var logEntry = new OtlpLogEntry(record, application);
294+
var logEntry = new OtlpLogEntry(record, application, scope);
277295

278296
// Insert log entry in the correct position based on timestamp.
279297
// Logs can be added out of order by different services.
@@ -525,13 +543,17 @@ internal void AddTracesCore(AddContext context, OtlpApplication application, Rep
525543
{
526544
foreach (var scopeSpan in scopeSpans)
527545
{
528-
OtlpTraceScope? traceScope;
546+
OtlpScope? scope;
529547
try
530548
{
531-
if (!_traceScopes.TryGetValue(scopeSpan.Scope.Name, out traceScope))
549+
// The instrumentation scope information for the spans in this message.
550+
// Semantically when InstrumentationScope isn't set, it is equivalent with
551+
// an empty instrumentation scope name (unknown).
552+
var name = scopeSpan.Scope?.Name ?? string.Empty;
553+
if (!_traceScopes.TryGetValue(name, out scope))
532554
{
533-
traceScope = new OtlpTraceScope(scopeSpan.Scope);
534-
_traceScopes.Add(scopeSpan.Scope.Name, traceScope);
555+
scope = (scopeSpan.Scope != null) ? new OtlpScope(scopeSpan.Scope) : OtlpScope.Empty;
556+
_traceScopes.Add(name, scope);
535557
}
536558
}
537559
catch (Exception ex)
@@ -557,7 +579,7 @@ internal void AddTracesCore(AddContext context, OtlpApplication application, Rep
557579
}
558580
else if (!TryGetTraceById(_traces, span.TraceId.Memory, out trace))
559581
{
560-
trace = new OtlpTrace(span.TraceId.Memory, traceScope);
582+
trace = new OtlpTrace(span.TraceId.Memory, scope);
561583
newTrace = true;
562584
}
563585

‎tests/Aspire.Dashboard.Tests/TelemetryRepositoryTests/LogTests.cs‎

Lines changed: 17 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -31,6 +31,7 @@ public void AddLogs()
3131
{
3232
new ScopeLogs
3333
{
34+
Scope = CreateScope("TestLogger"),
3435
LogRecords = { CreateLogRecord() }
3536
}
3637
}
@@ -62,6 +63,7 @@ public void AddLogs()
6263
Assert.Equal("5465737454726163654964", app.TraceId);
6364
Assert.Equal("Test {Log}", app.OriginalFormat);
6465
Assert.Equal("Test Value!", app.Message);
66+
Assert.Equal("TestLogger", app.Scope.ScopeName);
6567
Assert.Collection(app.Properties,
6668
p =>
6769
{
@@ -121,7 +123,11 @@ public void AddLogs_MultipleOutOfOrder()
121123
Filters = []
122124
});
123125
Assert.Collection(logs.Items,
124-
l => Assert.Equal("1", l.Message),
126+
l =>
127+
{
128+
Assert.Equal("1", l.Message);
129+
Assert.Equal("", l.Scope.ScopeName);
130+
},
125131
l => Assert.Equal("2", l.Message),
126132
l => Assert.Equal("3", l.Message),
127133
l => Assert.Equal("4", l.Message),
@@ -150,6 +156,7 @@ public void AddLogs_Error_UnviewedCount()
150156
{
151157
new ScopeLogs
152158
{
159+
Scope = CreateScope("TestLogger"),
153160
LogRecords =
154161
{
155162
CreateLogRecord(time: s_testTime.AddMinutes(1), message: "1", severity: SeverityNumber.Trace),
@@ -169,6 +176,7 @@ public void AddLogs_Error_UnviewedCount()
169176
{
170177
new ScopeLogs
171178
{
179+
Scope = CreateScope("TestLogger"),
172180
LogRecords =
173181
{
174182
CreateLogRecord(time: s_testTime.AddMinutes(1), message: "1", severity: SeverityNumber.Fatal)
@@ -224,6 +232,7 @@ public void AddLogs_Error_UnviewedCount_WithReadSubscriptionAll()
224232
{
225233
new ScopeLogs
226234
{
235+
Scope = CreateScope("TestLogger"),
227236
LogRecords =
228237
{
229238
CreateLogRecord(time: s_testTime.AddMinutes(1), message: "1", severity: SeverityNumber.Error),
@@ -238,6 +247,7 @@ public void AddLogs_Error_UnviewedCount_WithReadSubscriptionAll()
238247
{
239248
new ScopeLogs
240249
{
250+
Scope = CreateScope("TestLogger"),
241251
LogRecords =
242252
{
243253
CreateLogRecord(time: s_testTime.AddMinutes(1), message: "1", severity: SeverityNumber.Fatal)
@@ -274,6 +284,7 @@ public void AddLogs_Error_UnviewedCount_WithReadSubscriptionOneApp()
274284
{
275285
new ScopeLogs
276286
{
287+
Scope = CreateScope("TestLogger"),
277288
LogRecords =
278289
{
279290
CreateLogRecord(time: s_testTime.AddMinutes(1), message: "1", severity: SeverityNumber.Error),
@@ -288,6 +299,7 @@ public void AddLogs_Error_UnviewedCount_WithReadSubscriptionOneApp()
288299
{
289300
new ScopeLogs
290301
{
302+
Scope = CreateScope("TestLogger"),
291303
LogRecords =
292304
{
293305
CreateLogRecord(time: s_testTime.AddMinutes(1), message: "1", severity: SeverityNumber.Fatal)
@@ -325,6 +337,7 @@ public void AddLogs_Error_UnviewedCount_WithNonReadSubscription()
325337
{
326338
new ScopeLogs
327339
{
340+
Scope = CreateScope("TestLogger"),
328341
LogRecords =
329342
{
330343
CreateLogRecord(time: s_testTime.AddMinutes(1), message: "1", severity: SeverityNumber.Error),
@@ -399,6 +412,7 @@ public async Task Subscriptions_AddLog()
399412
{
400413
new ScopeLogs
401414
{
415+
Scope = CreateScope("TestLogger"),
402416
LogRecords = { CreateLogRecord() }
403417
}
404418
}
@@ -435,6 +449,7 @@ public async Task Subscriptions_AddLog()
435449
{
436450
new ScopeLogs
437451
{
452+
Scope = CreateScope("TestLogger"),
438453
LogRecords = { CreateLogRecord() }
439454
}
440455
}
@@ -482,6 +497,7 @@ public void Unsubscribe()
482497
{
483498
new ScopeLogs
484499
{
500+
Scope = CreateScope("TestLogger"),
485501
LogRecords = { CreateLogRecord() }
486502
}
487503
}

‎tests/Aspire.Dashboard.Tests/TelemetryRepositoryTests/TraceTests.cs‎

Lines changed: 6 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -87,7 +87,6 @@ public void AddTraces_Traces_MultipleOutOrOrder()
8787
{
8888
new ScopeSpans
8989
{
90-
Scope = CreateScope(),
9190
Spans =
9291
{
9392
CreateSpan(traceId: "1", spanId: "1-2", startTime: s_testTime.AddMinutes(5), endTime: s_testTime.AddMinutes(10), parentSpanId: "1-1")
@@ -108,7 +107,6 @@ public void AddTraces_Traces_MultipleOutOrOrder()
108107
{
109108
new ScopeSpans
110109
{
111-
Scope = CreateScope(),
112110
Spans =
113111
{
114112
CreateSpan(traceId: "2", spanId: "2-1", startTime: s_testTime.AddMinutes(3), endTime: s_testTime.AddMinutes(10))
@@ -140,12 +138,14 @@ public void AddTraces_Traces_MultipleOutOrOrder()
140138
AssertId("2", trace.TraceId);
141139
AssertId("2-1", trace.FirstSpan.SpanId);
142140
AssertId("2-1", trace.RootSpan!.SpanId);
141+
Assert.Equal("", trace.TraceScope.ScopeName);
143142
},
144143
trace =>
145144
{
146145
AssertId("1", trace.TraceId);
147146
AssertId("1-2", trace.FirstSpan.SpanId);
148147
Assert.Null(trace.RootSpan);
148+
Assert.Equal("", trace.TraceScope.ScopeName);
149149
});
150150

151151
var addContext3 = new AddContext();
@@ -158,7 +158,6 @@ public void AddTraces_Traces_MultipleOutOrOrder()
158158
{
159159
new ScopeSpans
160160
{
161-
Scope = CreateScope(),
162161
Spans =
163162
{
164163
CreateSpan(traceId: "1", spanId: "1-1", startTime: s_testTime.AddMinutes(1), endTime: s_testTime.AddMinutes(10))
@@ -181,13 +180,17 @@ public void AddTraces_Traces_MultipleOutOrOrder()
181180
{
182181
AssertId("1", trace.TraceId);
183182
AssertId("1-1", trace.FirstSpan.SpanId);
183+
AssertId("", trace.FirstSpan.ScopeName);
184184
AssertId("1-1", trace.RootSpan!.SpanId);
185+
Assert.Equal("", trace.TraceScope.ScopeName);
185186
},
186187
trace =>
187188
{
188189
AssertId("2", trace.TraceId);
189190
AssertId("2-1", trace.FirstSpan.SpanId);
191+
AssertId("", trace.FirstSpan.ScopeName);
190192
AssertId("2-1", trace.RootSpan!.SpanId);
193+
Assert.Equal("", trace.TraceScope.ScopeName);
191194
});
192195
}
193196

0 commit comments

Comments
 (0)