Skip to content

Commit

Permalink
[OneBot] fix(logging): better logging message
Browse files Browse the repository at this point in the history
  • Loading branch information
CrackTC committed Jun 12, 2024
1 parent fa0f215 commit 729715d
Show file tree
Hide file tree
Showing 3 changed files with 83 additions and 45 deletions.
22 changes: 15 additions & 7 deletions Lagrange.OneBot/Core/Network/Service/HttpPostService.cs
Original file line number Diff line number Diff line change
Expand Up @@ -42,7 +42,7 @@ public async ValueTask SendJsonAsync<T>(T payload, string? identifier, Cancellat
if (payload is OneBotResult) return; // ignore api result

var json = JsonSerializer.Serialize(payload);
Log.LogSendingData(_logger, Tag, json);
Log.LogSendingData(_logger, Tag, _url.ToString(), json);
using var request = new HttpRequestMessage(HttpMethod.Post, _url)
{
Headers = { { "X-Self-ID", context.BotUin.ToString() } },
Expand All @@ -60,7 +60,7 @@ public async ValueTask SendJsonAsync<T>(T payload, string? identifier, Cancellat
}
catch (HttpRequestException ex)
{
Log.LogPostFailed(_logger, ex, Tag);
Log.LogPostFailed(_logger, ex, Tag, _url.ToString());
}
}

Expand Down Expand Up @@ -122,13 +122,21 @@ private async Task HeartbeatLoop(CancellationToken token)

private static partial class Log
{
[LoggerMessage(EventId = 1, Level = LogLevel.Trace, Message = "[{tag}] Send: {data}")]
public static partial void LogSendingData(ILogger logger, string tag, string data);
private enum EventIds
{
SendingData = 1,

PostFailed = 1001,
InvalidUrl
}

[LoggerMessage(EventId = (int)EventIds.SendingData, Level = LogLevel.Trace, Message = "[{tag}] Send to {url}: {data}")]
public static partial void LogSendingData(ILogger logger, string tag, string url, string data);

[LoggerMessage(EventId = 5, Level = LogLevel.Error, Message = "[{tag}] Post failed")]
public static partial void LogPostFailed(ILogger logger, Exception ex, string tag);
[LoggerMessage(EventId = (int)EventIds.PostFailed, Level = LogLevel.Error, Message = "[{tag}] Post to {url} failed")]
public static partial void LogPostFailed(ILogger logger, Exception ex, string tag, string url);

[LoggerMessage(EventId = 10, Level = LogLevel.Error, Message = "[{tag}] Invalid configuration was detected, url: {url}")]
[LoggerMessage(EventId = (int)EventIds.InvalidUrl, Level = LogLevel.Error, Message = "[{tag}] Invalid configuration was detected, url: {url}")]
public static partial void LogInvalidUrl(ILogger logger, string tag, string url);
}
}
44 changes: 30 additions & 14 deletions Lagrange.OneBot/Core/Network/Service/HttpService.cs
Original file line number Diff line number Diff line change
Expand Up @@ -90,7 +90,7 @@ private async Task HandleRequestAsync(HttpListenerContext context, CancellationT
(query["access_token"] is { } accessToken ? $"Bearer {accessToken}" : null);
if (authorization is null)
{
Log.LogAuthFailed(_logger, identifier);
Log.LogAuthFailed(_logger, identifier, request.RemoteEndPoint.ToString());
response.StatusCode = (int)HttpStatusCode.Unauthorized;
response.Headers.Add("WWW-Authenticate", "Bearer");
response.Close();
Expand All @@ -99,7 +99,7 @@ private async Task HandleRequestAsync(HttpListenerContext context, CancellationT

if (authorization != $"Bearer {_options.AccessToken}")
{
Log.LogAuthFailed(_logger, identifier);
Log.LogAuthFailed(_logger, identifier, request.RemoteEndPoint.ToString());
response.StatusCode = (int)HttpStatusCode.Forbidden;
response.Close();
return;
Expand Down Expand Up @@ -210,39 +210,55 @@ public async ValueTask SendJsonAsync<T>(T json, string? identifier = null,

private static partial class Log
{
[LoggerMessage(EventId = 0, Level = LogLevel.Information, Message = "HttpService started at {prefix}")]
private enum EventIds
{
Started = 1,
Received,
Send,

StartFailed = 1001,
CloseFailed,
GetContextError,
HandleError,
AuthFailed,
CannotParseMediaType,
UnsupportedContentType,
UnsupportedMethod,
}

[LoggerMessage(EventId = (int)EventIds.Started, Level = LogLevel.Information, Message = "HttpService started at {prefix}")]
public static partial void LogStarted(ILogger logger, string prefix);

[LoggerMessage(EventId = 1, Level = LogLevel.Information, Message = "Receive(Conn: {identifier}: {s})")]
[LoggerMessage(EventId = (int)EventIds.Received, Level = LogLevel.Information, Message = "Receive(Conn: {identifier}: {s})")]
public static partial void LogReceived(ILogger logger, string identifier, string s);

[LoggerMessage(EventId = 2, Level = LogLevel.Trace, Message = "Send(Conn: {identifier}: {s})")]
[LoggerMessage(EventId = (int)EventIds.Send, Level = LogLevel.Trace, Message = "Send(Conn: {identifier}: {s})")]
public static partial void LogSend(ILogger logger, string identifier, string s);

[LoggerMessage(EventId = 992, Level = LogLevel.Warning, Message = "Cannot parse media type: {mediaType}")]
[LoggerMessage(EventId = (int)EventIds.CannotParseMediaType, Level = LogLevel.Warning, Message = "Cannot parse media type: {mediaType}")]
public static partial void LogCannotParseMediaType(ILogger logger, string mediaType);

[LoggerMessage(EventId = 993, Level = LogLevel.Warning, Message = "Conn: {identifier} auth failed")]
public static partial void LogAuthFailed(ILogger logger, string identifier);
[LoggerMessage(EventId = (int)EventIds.AuthFailed, Level = LogLevel.Warning, Message = "Conn: {identifier} from {ip} auth failed")]
public static partial void LogAuthFailed(ILogger logger, string identifier, string ip);

[LoggerMessage(EventId = 994, Level = LogLevel.Warning, Message = "Unsupported content type: {contentType}")]
[LoggerMessage(EventId = (int)EventIds.UnsupportedContentType, Level = LogLevel.Warning, Message = "Unsupported content type: {contentType}")]
public static partial void LogUnsupportedContentType(ILogger logger, string contentType);

[LoggerMessage(EventId = 995, Level = LogLevel.Warning, Message = "Unsupported method: {method}")]
[LoggerMessage(EventId = (int)EventIds.UnsupportedMethod, Level = LogLevel.Warning, Message = "Unsupported method: {method}")]
public static partial void LogUnsupportedMethod(ILogger logger, string method);

[LoggerMessage(EventId = 996, Level = LogLevel.Warning,
[LoggerMessage(EventId = (int)EventIds.HandleError, Level = LogLevel.Warning,
Message = "An error occurred while handling the request")]
public static partial void LogHandleError(ILogger logger, Exception e);

[LoggerMessage(EventId = 997, Level = LogLevel.Warning,
[LoggerMessage(EventId = (int)EventIds.GetContextError, Level = LogLevel.Warning,
Message = "An error occurred while getting the context")]
public static partial void LogGetContextError(ILogger logger, Exception e);

[LoggerMessage(EventId = 998, Level = LogLevel.Warning, Message = "Failed to gracefully close the listener")]
[LoggerMessage(EventId = (int)EventIds.CloseFailed, Level = LogLevel.Warning, Message = "Failed to gracefully close the listener")]
public static partial void LogCloseFailed(ILogger logger, Exception e);

[LoggerMessage(EventId = 999, Level = LogLevel.Error,
[LoggerMessage(EventId = (int)EventIds.StartFailed, Level = LogLevel.Error,
Message = "An error occurred while starting the listener")]
public static partial void LogStartFailed(ILogger logger, Exception e);
}
Expand Down
62 changes: 38 additions & 24 deletions Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,8 @@ public partial class ReverseWSService(IOptionsSnapshot<ReverseWSServiceOptions>
{
private const string Tag = nameof(ReverseWSService);

private string _urlStr = string.Empty;

public event EventHandler<MsgRecvEventArgs>? OnMessageReceived;

private readonly ReverseWSServiceOptions _options = options.Value;
Expand Down Expand Up @@ -75,7 +77,7 @@ protected async ValueTask SendJsonAsync<T>(ClientWebSocket ws, T payload, Cancel
{
var json = JsonSerializer.Serialize(payload);
var buffer = Encoding.UTF8.GetBytes(json);
Log.LogSendingData(_logger, Tag, json);
Log.LogSendingData(_logger, Tag, _urlStr, json);
await semaphore.WaitAsync(token);
try
{
Expand All @@ -100,17 +102,17 @@ protected ClientWebSocket CreateDefaultWebSocket(string role)

protected override async Task ExecuteAsync(CancellationToken stoppingToken)
{
string urlstr = $"{_options.Host}:{_options.Port}{_options.Suffix}";
_urlStr = $"{_options.Host}:{_options.Port}{_options.Suffix}";
if (!_options.Host.StartsWith("ws://") && !_options.Host.StartsWith("wss://"))
{
urlstr = "ws://" + urlstr;
_urlStr = "ws://" + _urlStr;
}
string apiurlstr = $"{urlstr}{_options.ApiSuffix}";
string eventurlstr = $"{urlstr}{_options.EventSuffix}";
string apiurlstr = $"{_urlStr}{_options.ApiSuffix}";
string eventurlstr = $"{_urlStr}{_options.EventSuffix}";

if (!Uri.TryCreate(urlstr, UriKind.Absolute, out var url))
if (!Uri.TryCreate(_urlStr, UriKind.Absolute, out var url))
{
Log.LogInvalidUrl(_logger, Tag, urlstr);
Log.LogInvalidUrl(_logger, Tag, _urlStr);
return;
}
if (!Uri.TryCreate(apiurlstr, UriKind.Absolute, out var apiUrl))
Expand All @@ -136,6 +138,7 @@ protected override async Task ExecuteAsync(CancellationToken stoppingToken)
ConnCtx = connCtx;
await connTask;

Log.LogConnected(_logger, Tag, _urlStr);
var lifecycle = new OneBotLifecycle(context.BotUin, "connect");
await SendJsonAsync(ws, lifecycle, stoppingToken);

Expand Down Expand Up @@ -185,13 +188,13 @@ protected override async Task ExecuteAsync(CancellationToken stoppingToken)
}
catch (WebSocketException e) when (e.InnerException is HttpRequestException)
{
Log.LogClientReconnect(_logger, Tag, _options.ReconnectInterval);
Log.LogClientReconnect(_logger, Tag, _urlStr, _options.ReconnectInterval);
var interval = TimeSpan.FromMilliseconds(_options.ReconnectInterval);
await Task.Delay(interval, stoppingToken);
}
catch (Exception e)
{
Log.LogClientDisconnected(_logger, e, Tag);
Log.LogClientDisconnected(_logger, e, Tag, _urlStr);
var interval = TimeSpan.FromMilliseconds(_options.ReconnectInterval);
await Task.Delay(interval, stoppingToken);
}
Expand Down Expand Up @@ -219,7 +222,7 @@ private async Task ReceiveLoop(ClientWebSocket ws, CancellationToken token)
if (received == buffer.Length) Array.Resize(ref buffer, received << 1);
}
string text = Encoding.UTF8.GetString(buffer, 0, received);
Log.LogDataReceived(_logger, Tag, text);
Log.LogDataReceived(_logger, Tag, _urlStr, text);
OnMessageReceived?.Invoke(this, new MsgRecvEventArgs(text)); // Handle user handlers error?
}
}
Expand Down Expand Up @@ -250,34 +253,45 @@ private async Task HeartbeatLoop(ClientWebSocket ws, CancellationToken token)

private static partial class Log
{
[LoggerMessage(EventId = 1, Level = LogLevel.Trace, Message = "[{tag}] Send: {data}")]
public static partial void LogSendingData(ILogger logger, string tag, string data);
private enum EventIds
{
Connected = 1,
SendingData,
DataReceived,

ClientDisconnected = 1001,
ClientReconnect,
InvalidUrl
}

public static void LogDataReceived(ILogger logger, string tag, string data)
[LoggerMessage(EventId = (int)EventIds.Connected, Level = LogLevel.Trace, Message = "[{tag}] Connect: {url}")]
public static partial void LogConnected(ILogger logger, string tag, string url);

[LoggerMessage(EventId = (int)EventIds.SendingData, Level = LogLevel.Trace, Message = "[{tag}] Send: {data}")]
public static partial void LogSendingData(ILogger logger, string tag, string url, string data);

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (win-x64)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (win-x64)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (win-x86)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (win-x86)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (linux-x64)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (linux-x64)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (linux-arm)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (linux-arm)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (linux-arm64)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (linux-arm64)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (osx-x64)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (osx-x64)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (osx-arm64)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (osx-arm64)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (linux-musl-x64)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (linux-musl-x64)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (linux-musl-arm)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (linux-musl-arm)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (linux-musl-arm64)

Argument 'url' is not referenced from the logging message

Check warning on line 271 in Lagrange.OneBot/Core/Network/Service/ReverseWSService.cs

View workflow job for this annotation

GitHub Actions / build (linux-musl-arm64)

Argument 'url' is not referenced from the logging message

public static void LogDataReceived(ILogger logger, string tag, string url, string data)
{
if (logger.IsEnabled(LogLevel.Trace))
{
if (data.Length > 1024)
{
data = string.Concat(data.AsSpan(0, 1024), "...", (data.Length - 1024).ToString(), "bytes");
}
InternalLogDataReceived(logger, tag, data);
InternalLogDataReceived(logger, tag, url, data);
}
}

[LoggerMessage(EventId = 2, Level = LogLevel.Trace, Message = "[{tag}] Receive: {data}", SkipEnabledCheck = true)]
private static partial void InternalLogDataReceived(ILogger logger, string tag, string data);

[LoggerMessage(EventId = 3, Level = LogLevel.Warning, Message = "[{tag}] Client disconnected")]
public static partial void LogClientDisconnected(ILogger logger, Exception e, string tag);
[LoggerMessage(EventId = (int)EventIds.DataReceived, Level = LogLevel.Trace, Message = "[{tag}] Receive client {url}: {data}", SkipEnabledCheck = true)]
private static partial void InternalLogDataReceived(ILogger logger, string tag, string url, string data);

[LoggerMessage(EventId = 4, Level = LogLevel.Information, Message = "[{tag}] Client reconnecting at interval of {interval}")]
public static partial void LogClientReconnect(ILogger logger, string tag, uint interval);
[LoggerMessage(EventId = (int)EventIds.ClientDisconnected, Level = LogLevel.Warning, Message = "[{tag}] Client {url} disconnected")]
public static partial void LogClientDisconnected(ILogger logger, Exception e, string tag, string url);

[LoggerMessage(EventId = 5, Level = LogLevel.Error, Message = "[{tag}] Client connect failed, reconnect after {interval} millisecond")]
public static partial void LogConnectFailed(ILogger logger, string tag, uint interval);
[LoggerMessage(EventId = (int)EventIds.ClientReconnect, Level = LogLevel.Information, Message = "[{tag}] Client {url} reconnecting at interval of {interval}")]
public static partial void LogClientReconnect(ILogger logger, string tag, string url, uint interval);

[LoggerMessage(EventId = 10, Level = LogLevel.Error, Message = "[{tag}] Invalid configuration was detected, url: {url}")]
[LoggerMessage(EventId = (int)EventIds.InvalidUrl, Level = LogLevel.Error, Message = "[{tag}] Invalid configuration was detected, url: {url}")]
public static partial void LogInvalidUrl(ILogger logger, string tag, string url);
}
}

0 comments on commit 729715d

Please sign in to comment.