Skip to content

Commit a949010

Browse files
authored
Clean up system level logs in resource output (#11915)
1 parent 33eff91 commit a949010

File tree

4 files changed

+354
-52
lines changed

4 files changed

+354
-52
lines changed

src/Aspire.Hosting/Dcp/DcpHost.cs

Lines changed: 6 additions & 46 deletions
Original file line numberDiff line numberDiff line change
@@ -7,7 +7,6 @@
77
using System.Net.Sockets;
88
using System.Text;
99
using Aspire.Dashboard.Utils;
10-
using Aspire.Hosting;
1110
using Aspire.Hosting.ApplicationModel;
1211
using Aspire.Hosting.Dcp.Process;
1312
using Aspire.Hosting.Resources;
@@ -274,63 +273,24 @@ private async Task LogSocketOutputAsync(Socket socket, CancellationToken cancell
274273

275274
(ILogger, LogLevel, string message) GetLogInfo(ReadOnlySpan<byte> line)
276275
{
277-
// The log format is
278-
// <date>\t<level>\t<category>\t<log message>
279-
// e.g. 2023-09-19T20:40:50.509-0700 info dcpctrl.ServiceReconciler service /apigateway is now in state Ready {"ServiceName": {"name":"apigateway"}}
280-
281-
var tab = line.IndexOf((byte)'\t');
282-
var date = line[..tab];
283-
line = line[(tab + 1)..];
284-
tab = line.IndexOf((byte)'\t');
285-
var level = line[..tab];
286-
line = line[(tab + 1)..];
287-
tab = line.IndexOf((byte)'\t');
288-
var category = line[..tab];
289-
line = line[(tab + 1)..];
290-
291-
// Trim trailing carriage return.
292-
if (line[^1] == '\r')
276+
if (!DcpLogParser.TryParseDcpLog(line, out var parsedMessage, out var logLevel, out var category))
293277
{
294-
line = line[0..^1];
295-
}
296-
297-
var message = line;
298-
299-
var logLevel = LogLevel.Information;
300-
301-
if (level.SequenceEqual("info"u8))
302-
{
303-
logLevel = LogLevel.Information;
304-
}
305-
else if (level.SequenceEqual("error"u8))
306-
{
307-
logLevel = LogLevel.Error;
308-
}
309-
else if (level.SequenceEqual("warning"u8))
310-
{
311-
logLevel = LogLevel.Warning;
312-
}
313-
else if (level.SequenceEqual("debug"u8))
314-
{
315-
logLevel = LogLevel.Debug;
316-
}
317-
else if (level.SequenceEqual("trace"u8))
318-
{
319-
logLevel = LogLevel.Trace;
278+
// If parsing fails, return a default logger and the line as-is
279+
return (_logger, LogLevel.Information, Encoding.UTF8.GetString(line));
320280
}
321281

322282
var hash = new HashCode();
323-
hash.AddBytes(category);
283+
hash.AddBytes(Encoding.UTF8.GetBytes(category));
324284
var hashValue = hash.ToHashCode();
325285

326286
if (!loggerCache.TryGetValue(hashValue, out var logger))
327287
{
328288
// loggerFactory.CreateLogger internally caches, but we may as well cache the logger as well as the string
329289
// for the lifetime of this socket
330-
loggerCache[hashValue] = logger = _loggerFactory.CreateLogger($"Aspire.Hosting.Dcp.{Encoding.UTF8.GetString(category)}");
290+
loggerCache[hashValue] = logger = _loggerFactory.CreateLogger($"Aspire.Hosting.Dcp.{category}");
331291
}
332292

333-
return (logger, logLevel, Encoding.UTF8.GetString(message));
293+
return (logger, logLevel, parsedMessage);
334294
}
335295

336296
try
Lines changed: 117 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,117 @@
1+
// Licensed to the .NET Foundation under one or more agreements.
2+
// The .NET Foundation licenses this file to you under the MIT license.
3+
4+
using System.Text;
5+
using Microsoft.Extensions.Logging;
6+
7+
namespace Aspire.Hosting.Dcp;
8+
9+
/// <summary>
10+
/// Helper class for parsing DCP-formatted log lines.
11+
/// DCP log format: &lt;date&gt;\t&lt;level&gt;\t&lt;category&gt;\t&lt;log message&gt;
12+
/// </summary>
13+
internal static class DcpLogParser
14+
{
15+
/// <summary>
16+
/// Tries to parse a DCP-formatted log line.
17+
/// </summary>
18+
/// <param name="line">The log line to parse (as bytes).</param>
19+
/// <param name="message">The extracted message.</param>
20+
/// <param name="logLevel">The extracted log level.</param>
21+
/// <param name="category">The extracted category.</param>
22+
/// <returns>True if the line was successfully parsed as a DCP log; false otherwise.</returns>
23+
public static bool TryParseDcpLog(ReadOnlySpan<byte> line, out string message, out LogLevel logLevel, out string category)
24+
{
25+
message = string.Empty;
26+
logLevel = LogLevel.Information;
27+
category = string.Empty;
28+
29+
try
30+
{
31+
// The log format is
32+
// <date>\t<level>\t<category>\t<log message>
33+
// e.g. 2023-09-19T20:40:50.509-0700 info dcpctrl.ServiceReconciler service /apigateway is now in state Ready {"ServiceName": {"name":"apigateway"}}
34+
35+
var tab = line.IndexOf((byte)'\t');
36+
if (tab < 0)
37+
{
38+
return false;
39+
}
40+
41+
// Skip date
42+
line = line[(tab + 1)..];
43+
44+
tab = line.IndexOf((byte)'\t');
45+
if (tab < 0)
46+
{
47+
return false;
48+
}
49+
50+
var level = line[..tab];
51+
line = line[(tab + 1)..];
52+
53+
tab = line.IndexOf((byte)'\t');
54+
if (tab < 0)
55+
{
56+
return false;
57+
}
58+
59+
var categorySpan = line[..tab];
60+
line = line[(tab + 1)..];
61+
62+
// Trim trailing carriage return.
63+
if (line.Length > 0 && line[^1] == '\r')
64+
{
65+
line = line[0..^1];
66+
}
67+
68+
var messageSpan = line;
69+
70+
// Parse log level
71+
if (level.SequenceEqual("info"u8))
72+
{
73+
logLevel = LogLevel.Information;
74+
}
75+
else if (level.SequenceEqual("error"u8))
76+
{
77+
logLevel = LogLevel.Error;
78+
}
79+
else if (level.SequenceEqual("warning"u8))
80+
{
81+
logLevel = LogLevel.Warning;
82+
}
83+
else if (level.SequenceEqual("debug"u8))
84+
{
85+
logLevel = LogLevel.Debug;
86+
}
87+
else if (level.SequenceEqual("trace"u8))
88+
{
89+
logLevel = LogLevel.Trace;
90+
}
91+
92+
message = Encoding.UTF8.GetString(messageSpan);
93+
category = Encoding.UTF8.GetString(categorySpan);
94+
return true;
95+
}
96+
catch
97+
{
98+
return false;
99+
}
100+
}
101+
102+
/// <summary>
103+
/// Tries to parse a DCP-formatted log line from a string.
104+
/// </summary>
105+
/// <param name="line">The log line to parse (as string).</param>
106+
/// <param name="message">The extracted message.</param>
107+
/// <param name="logLevel">The extracted log level.</param>
108+
/// <param name="isErrorLevel">True if the log level indicates an error.</param>
109+
/// <returns>True if the line was successfully parsed as a DCP log; false otherwise.</returns>
110+
public static bool TryParseDcpLog(string line, out string message, out LogLevel logLevel, out bool isErrorLevel)
111+
{
112+
var bytes = Encoding.UTF8.GetBytes(line);
113+
var result = TryParseDcpLog(bytes.AsSpan(), out message, out logLevel, out _);
114+
isErrorLevel = logLevel == LogLevel.Error;
115+
return result;
116+
}
117+
}

src/Aspire.Hosting/Dcp/ResourceLogSource.cs

Lines changed: 13 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -37,24 +37,24 @@ public async IAsyncEnumerator<LogEntryList> GetAsyncEnumerator(CancellationToken
3737
var startupStderrStream = await kubernetesService.GetLogStreamAsync(resource, Logs.StreamTypeStartupStdErr, cancellationToken, follow: follow, timestamps: true).ConfigureAwait(false);
3838
var startupStdoutStream = await kubernetesService.GetLogStreamAsync(resource, Logs.StreamTypeStartupStdOut, cancellationToken, follow: follow, timestamps: true).ConfigureAwait(false);
3939

40-
var startupStdoutStreamTask = Task.Run(() => StreamLogsAsync(startupStdoutStream, isError: false), cancellationToken);
40+
var startupStdoutStreamTask = Task.Run(() => StreamLogsAsync(startupStdoutStream, isError: false, parseDcpLogs: false), cancellationToken);
4141
streamTasks.Add(startupStdoutStreamTask);
4242

43-
var startupStderrStreamTask = Task.Run(() => StreamLogsAsync(startupStderrStream, isError: false), cancellationToken);
43+
var startupStderrStreamTask = Task.Run(() => StreamLogsAsync(startupStderrStream, isError: false, parseDcpLogs: false), cancellationToken);
4444
streamTasks.Add(startupStderrStreamTask);
4545

4646
var stdoutStream = await kubernetesService.GetLogStreamAsync(resource, Logs.StreamTypeStdOut, cancellationToken, follow: follow, timestamps: true).ConfigureAwait(false);
4747
var stderrStream = await kubernetesService.GetLogStreamAsync(resource, Logs.StreamTypeStdErr, cancellationToken, follow: follow, timestamps: true).ConfigureAwait(false);
4848

49-
var stdoutStreamTask = Task.Run(() => StreamLogsAsync(stdoutStream, isError: false), cancellationToken);
49+
var stdoutStreamTask = Task.Run(() => StreamLogsAsync(stdoutStream, isError: false, parseDcpLogs: false), cancellationToken);
5050
streamTasks.Add(stdoutStreamTask);
5151

52-
var stderrStreamTask = Task.Run(() => StreamLogsAsync(stderrStream, isError: true), cancellationToken);
52+
var stderrStreamTask = Task.Run(() => StreamLogsAsync(stderrStream, isError: true, parseDcpLogs: false), cancellationToken);
5353
streamTasks.Add(stderrStreamTask);
5454

5555
var systemStream = await kubernetesService.GetLogStreamAsync(resource, Logs.StreamTypeSystem, cancellationToken, follow: follow, timestamps: true).ConfigureAwait(false);
5656

57-
var systemStreamTask = Task.Run(() => StreamLogsAsync(systemStream, isError: false), cancellationToken);
57+
var systemStreamTask = Task.Run(() => StreamLogsAsync(systemStream, isError: false, parseDcpLogs: true), cancellationToken);
5858
streamTasks.Add(systemStreamTask);
5959

6060
// End the enumeration when both streams have been read to completion.
@@ -71,7 +71,7 @@ async Task WaitForStreamsToCompleteAsync()
7171
yield return batch;
7272
}
7373

74-
async Task StreamLogsAsync(Stream stream, bool isError)
74+
async Task StreamLogsAsync(Stream stream, bool isError, bool parseDcpLogs)
7575
{
7676
try
7777
{
@@ -84,6 +84,13 @@ async Task StreamLogsAsync(Stream stream, bool isError)
8484
return; // No more data
8585
}
8686

87+
// Parse DCP logs if requested
88+
if (parseDcpLogs && DcpLogParser.TryParseDcpLog(line, out var parsedMessage, out _, out var isErrorLevel))
89+
{
90+
line = parsedMessage;
91+
isError = isErrorLevel;
92+
}
93+
8794
var succeeded = channel.Writer.TryWrite((line, isError));
8895
if (!succeeded)
8996
{

0 commit comments

Comments
 (0)