Skip to content

Commit dba67dc

Browse files
smdnsmdn
committed
improved logging using with LoggerMessage
1 parent ff70494 commit dba67dc

File tree

2 files changed

+149
-40
lines changed

2 files changed

+149
-40
lines changed

‎src/Smdn.Net.MuninNode/Smdn.Net.MuninNode/NodeBase.LoggerMessages.cs‎

Lines changed: 108 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,108 @@
1+
// SPDX-FileCopyrightText: 2025 smdn <smdn@smdn.jp>
2+
// SPDX-License-Identifier: MIT
3+
using System;
4+
using System.Net;
5+
using System.Net.Sockets;
6+
7+
using Microsoft.Extensions.Logging;
8+
9+
namespace Smdn.Net.MuninNode;
10+
11+
#pragma warning disable IDE0040
12+
partial class NodeBase {
13+
#pragma warning restore IDE0040
14+
private static readonly Action<ILogger, Exception?> LogStartingNode = LoggerMessage.Define(
15+
LogLevel.Debug,
16+
eventId: default, // TODO
17+
formatString: "Starting munin-node listener."
18+
);
19+
private static readonly Action<ILogger, string, EndPoint?, Exception?> LogStartedNode = LoggerMessage.Define<string, EndPoint?>(
20+
LogLevel.Information,
21+
eventId: default, // TODO
22+
formatString: "Started munin-node '{HostName}' on '{EndPoint}'."
23+
);
24+
private static readonly Action<ILogger, Exception?> LogStartedAcceptingConnections = LoggerMessage.Define(
25+
LogLevel.Information,
26+
eventId: default, // TODO
27+
formatString: "Started accepting connections."
28+
);
29+
private static readonly Action<ILogger, Exception?> LogStoppedAcceptingConnections = LoggerMessage.Define(
30+
LogLevel.Debug,
31+
eventId: default, // TODO
32+
formatString: "Stopped accepting connections."
33+
);
34+
private static readonly Action<ILogger, Exception?> LogAcceptingConnection = LoggerMessage.Define(
35+
LogLevel.Debug,
36+
eventId: default, // TODO
37+
formatString: "Accepting a connection..."
38+
);
39+
private static readonly Action<ILogger, Exception?> LogAcceptedConnectionClosed = LoggerMessage.Define(
40+
LogLevel.Debug,
41+
eventId: default, // TODO
42+
formatString: "Accepted connection closed."
43+
);
44+
private static readonly Action<ILogger, EndPoint?, AddressFamily?, Exception?> LogConnectionCanNotAccept = LoggerMessage.Define<EndPoint?, AddressFamily?>(
45+
LogLevel.Information,
46+
eventId: default, // TODO
47+
formatString: "Can not accept connection from {RemoteEndPoint} ({RemoteEndPointAddressFamily})."
48+
);
49+
private static readonly Action<ILogger, Exception?> LogAccessRefused = LoggerMessage.Define(
50+
LogLevel.Warning,
51+
eventId: default, // TODO
52+
formatString: "Access refused."
53+
);
54+
private static readonly Action<ILogger, Exception?> LogSessionSendingBanner = LoggerMessage.Define(
55+
LogLevel.Debug,
56+
eventId: default, // TODO
57+
formatString: "Sending banner."
58+
);
59+
private static readonly Action<ILogger, Exception?> LogSessionClosedWhileSendingBanner = LoggerMessage.Define(
60+
LogLevel.Warning,
61+
eventId: default, // TODO
62+
formatString: "Client closed session while sending banner."
63+
);
64+
private static readonly Action<ILogger, Exception?> LogSessionUnexpectedEceptionWhileSendingBanner = LoggerMessage.Define(
65+
LogLevel.Error,
66+
eventId: default, // TODO
67+
formatString: "Unexpected exception occured while sending banner."
68+
);
69+
private static readonly Action<ILogger, Exception?> LogSessionStarted = LoggerMessage.Define(
70+
LogLevel.Information,
71+
eventId: default, // TODO
72+
formatString: "Session started."
73+
);
74+
private static readonly Action<ILogger, Exception?> LogSessionClosed = LoggerMessage.Define(
75+
LogLevel.Information,
76+
eventId: default, // TODO
77+
formatString: "Session closed."
78+
);
79+
private static readonly Action<ILogger, Exception?> LogSessionOperationCanceledWhileReceiving = LoggerMessage.Define(
80+
LogLevel.Warning,
81+
eventId: default, // TODO
82+
formatString: "Operation canceled while receiving."
83+
);
84+
private static readonly Action<ILogger, Exception?> LogSessionUnexpectedEceptionWhileReceiving = LoggerMessage.Define(
85+
LogLevel.Error,
86+
eventId: default, // TODO
87+
formatString: "Unexpected exception occured while receiving."
88+
);
89+
private static readonly Action<ILogger, Exception?> LogSessionClientDisconnectedWhileSeinding = LoggerMessage.Define(
90+
LogLevel.Information,
91+
eventId: default, // TODO
92+
formatString: "Client disconnected while sending."
93+
);
94+
private static readonly Action<ILogger, Exception?> LogSessionOperationCanceledWhileProcessingCommand = LoggerMessage.Define(
95+
LogLevel.Warning,
96+
eventId: default, // TODO
97+
formatString: "Operation canceled while processing command."
98+
);
99+
private static readonly Action<ILogger, Exception?> LogSessionUnexpectedEceptionWhileProcessingCommand = LoggerMessage.Define(
100+
LogLevel.Error,
101+
eventId: default, // TODO
102+
formatString: "Unexpected exception occured while processing command."
103+
);
104+
105+
private static readonly Func<ILogger, string, IDisposable?> LoggerScopeForSession = LoggerMessage.DefineScope<string>(
106+
formatString: "[{SessionId}]"
107+
);
108+
}

‎src/Smdn.Net.MuninNode/Smdn.Net.MuninNode/NodeBase.cs‎

Lines changed: 41 additions & 40 deletions
Original file line numberDiff line numberDiff line change
@@ -1,9 +1,5 @@
11
// SPDX-FileCopyrightText: 2021 smdn <smdn@smdn.jp>
22
// SPDX-License-Identifier: MIT
3-
4-
// TODO: use LoggerMessage.Define
5-
#pragma warning disable CA1848 // For improved performance, use the LoggerMessage delegates instead of calling 'LoggerExtensions.LogInformation(ILogger, string?, params object?[])'
6-
73
using System;
84
using System.Buffers;
95
using System.Collections.Generic;
@@ -191,7 +187,8 @@ async ValueTask StartAsyncCore()
191187
{
192188
cancellationToken.ThrowIfCancellationRequested();
193189

194-
Logger?.LogInformation("starting");
190+
if (Logger is not null)
191+
LogStartingNode(Logger, null);
195192

196193
listener = await listenerFactory.CreateAsync(
197194
endPoint: GetLocalEndPointToBind(),
@@ -204,7 +201,8 @@ async ValueTask StartAsyncCore()
204201

205202
await listener.StartAsync(cancellationToken).ConfigureAwait(false);
206203

207-
Logger?.LogInformation("started (end point: {EndPoint})", listener.EndPoint);
204+
if (Logger is not null)
205+
LogStartedNode(Logger, HostName, listener.EndPoint, null);
208206
}
209207
}
210208

@@ -247,7 +245,8 @@ CancellationToken cancellationToken
247245
{
248246
ThrowIfDisposed();
249247

250-
Logger?.LogInformation("starting to accept");
248+
if (Logger is not null)
249+
LogStartedAcceptingConnections(Logger, null);
251250

252251
try {
253252
for (; ; ) {
@@ -266,7 +265,8 @@ CancellationToken cancellationToken
266265
throw;
267266
}
268267

269-
Logger?.LogInformation("stopped to accept");
268+
if (Logger is not null)
269+
LogStoppedAcceptingConnections(Logger, null);
270270
}
271271

272272
/// <summary>
@@ -287,7 +287,8 @@ public async ValueTask AcceptSingleSessionAsync(
287287

288288
ThrowIfPluginProviderIsNull();
289289

290-
Logger?.LogInformation("accepting...");
290+
if (Logger is not null)
291+
LogAcceptingConnection(Logger, null);
291292

292293
var client = await listener.AcceptAsync(
293294
cancellationToken: cancellationToken
@@ -310,24 +311,21 @@ await ProcessSessionAsync(
310311
finally {
311312
await client.DisposeAsync().ConfigureAwait(false);
312313

313-
Logger?.LogInformation("connection closed");
314+
if (Logger is not null)
315+
LogAcceptedConnectionClosed(Logger, null);
314316
}
315317

316318
bool CanAccept(IMuninNodeClient client)
317319
{
318320
if (client.EndPoint is not IPEndPoint remoteIPEndPoint) {
319-
Logger?.LogWarning(
320-
"cannot accept {RemoteEndPoint} ({RemoteEndPointAddressFamily})",
321-
client.EndPoint?.ToString() ?? "(null)",
322-
client.EndPoint?.AddressFamily
323-
);
324-
321+
if (Logger is not null)
322+
LogConnectionCanNotAccept(Logger, client.EndPoint, client.EndPoint?.AddressFamily, null);
325323
return false;
326324
}
327325

328326
if (accessRule is not null && !accessRule.IsAcceptable(remoteIPEndPoint)) {
329-
Logger?.LogWarning("access refused");
330-
327+
if (Logger is not null)
328+
LogAccessRefused(Logger, null);
331329
return false;
332330
}
333331

@@ -342,9 +340,8 @@ CancellationToken cancellationToken
342340
{
343341
cancellationToken.ThrowIfCancellationRequested();
344342

345-
var sessionId = GenerateSessionId(listener!.EndPoint, client.EndPoint);
346-
347-
Logger?.LogDebug("sending banner");
343+
if (Logger is not null)
344+
LogSessionSendingBanner(Logger, null);
348345

349346
try {
350347
await SendResponseAsync(
@@ -354,27 +351,31 @@ await SendResponseAsync(
354351
).ConfigureAwait(false);
355352
}
356353
catch (MuninNodeClientDisconnectedException) {
357-
Logger?.LogWarning("client closed session while sending banner");
354+
if (Logger is not null)
355+
LogSessionClosedWhileSendingBanner(Logger, null);
358356

359357
return;
360358
}
361359
#pragma warning disable CA1031
362360
catch (Exception ex) {
363-
Logger?.LogCritical(
364-
ex,
365-
"unexpected exception occured while sending banner"
366-
);
361+
if (Logger is not null)
362+
LogSessionUnexpectedEceptionWhileSendingBanner(Logger, ex);
367363

368364
return;
369365
}
370366
#pragma warning restore CA1031
371367

372368
cancellationToken.ThrowIfCancellationRequested();
373369

370+
var sessionId = GenerateSessionId(listener!.EndPoint, client.EndPoint);
371+
374372
// begin logger scope with this session id
375-
using var scope = Logger?.BeginScope(sessionId);
373+
using var scope = Logger is null
374+
? null
375+
: LoggerScopeForSession(Logger, sessionId);
376376

377-
Logger?.LogInformation("session started");
377+
if (Logger is not null)
378+
LogSessionStarted(Logger, null);
378379

379380
try {
380381
if (PluginProvider.SessionCallback is not null)
@@ -393,7 +394,8 @@ await Task.WhenAll(
393394
ProcessCommandAsync(client, pipe.Reader, cancellationToken)
394395
).ConfigureAwait(false);
395396

396-
Logger?.LogInformation("session closed");
397+
if (Logger is not null)
398+
LogSessionClosed(Logger, null);
397399
}
398400
finally {
399401
foreach (var plugin in PluginProvider.Plugins) {
@@ -447,15 +449,14 @@ CancellationToken cancellationToken
447449
break;
448450
}
449451
catch (OperationCanceledException) {
450-
Logger?.LogInformation("operation canceled");
452+
if (Logger is not null)
453+
LogSessionOperationCanceledWhileReceiving(Logger, null);
451454
throw;
452455
}
453456
#pragma warning disable CA1031
454457
catch (Exception ex) {
455-
Logger?.LogError(
456-
ex,
457-
"unexpected exception while receiving"
458-
);
458+
if (Logger is not null)
459+
LogSessionUnexpectedEceptionWhileReceiving(Logger, ex);
459460
break; // swallow
460461
}
461462
#pragma warning restore CA1031
@@ -495,19 +496,19 @@ await RespondToCommandAsync(
495496
}
496497
}
497498
catch (MuninNodeClientDisconnectedException) {
498-
Logger?.LogInformation("client disconnected");
499+
if (Logger is not null)
500+
LogSessionClientDisconnectedWhileSeinding(Logger, null);
499501
break; // expected exception
500502
}
501503
catch (OperationCanceledException) {
502-
Logger?.LogInformation("operation canceled");
504+
if (Logger is not null)
505+
LogSessionOperationCanceledWhileProcessingCommand(Logger, null);
503506
throw;
504507
}
505508
#pragma warning disable CA1031
506509
catch (Exception ex) {
507-
Logger?.LogCritical(
508-
ex,
509-
"unexpected exception while processing command"
510-
);
510+
if (Logger is not null)
511+
LogSessionUnexpectedEceptionWhileProcessingCommand(Logger, ex);
511512

512513
await client.DisconnectAsync(cancellationToken).ConfigureAwait(false);
513514

0 commit comments

Comments
 (0)