diff --git a/src/libp2p/Libp2p.Core/Channel.cs b/src/libp2p/Libp2p.Core/Channel.cs index 5b1bce1c..45407426 100644 --- a/src/libp2p/Libp2p.Core/Channel.cs +++ b/src/libp2p/Libp2p.Core/Channel.cs @@ -150,7 +150,7 @@ public async ValueTask> ReadAsync(int length, { anotherChunk = _bytes; bytesToRead -= _bytes.Length; - _logger?.LogTrace("Read chunk {0} bytes", _bytes.Length); + _logger?.ReadChunk(_bytes.Length); _bytes = default; _read.Release(); _canWrite.Release(); @@ -159,7 +159,7 @@ public async ValueTask> ReadAsync(int length, { anotherChunk = _bytes.Slice(0, bytesToRead); _bytes = _bytes.Slice(bytesToRead, _bytes.End); - _logger?.LogTrace("Read enough {0} bytes", anotherChunk.Length); + _logger?.ReadEnough(_bytes.Length); bytesToRead = 0; _canRead.Release(); } @@ -185,7 +185,7 @@ public async ValueTask WriteAsync(ReadOnlySequence bytes) throw new InvalidProgramException(); } - _logger?.LogTrace("Write {0} bytes", bytes.Length); + _logger?.WriteBytes(bytes.Length); if (bytes.Length == 0) { diff --git a/src/libp2p/Libp2p.Core/ChannelFactory.cs b/src/libp2p/Libp2p.Core/ChannelFactory.cs index e78231da..d3168fc3 100644 --- a/src/libp2p/Libp2p.Core/ChannelFactory.cs +++ b/src/libp2p/Libp2p.Core/ChannelFactory.cs @@ -24,16 +24,16 @@ public ChannelFactory(IServiceProvider serviceProvider) public IChannel SubDial(IPeerContext context, IChannelRequest? req = null) { IProtocol? subProtocol = req?.SubProtocol ?? SubProtocols.FirstOrDefault(); - Channel chan = CreateChannel(subProtocol); ChannelFactory? sf = _factories[subProtocol] as ChannelFactory; - _logger?.LogDebug("Dial {chan} {sf}", chan.Id, sf.SubProtocols); + _logger?.LogAction(nameof(SubDial), chan.Id, subProtocol.Id, sf?.SubProtocols.Select(protocol => protocol.Id) ?? Enumerable.Empty()); + _ = subProtocol.DialAsync(chan.Reverse, sf, context).ContinueWith(async t => { if (!t.IsCompletedSuccessfully) { - _logger?.LogError("Dial error {proto} via {chan}: {error}", chan.Id, subProtocol.Id, t.Exception?.Message ?? "unknown"); + _logger?.LogCompletedUnsuccessfully(nameof(SubDial), chan.Id, subProtocol.Id, t.Exception, t.Exception?.Message ?? "unknown"); } if (!chan.IsClosed) { @@ -50,20 +50,17 @@ public IChannel SubDial(IPeerContext context, IChannelRequest? req = null) public IChannel SubListen(IPeerContext context, IChannelRequest? req = null) { IProtocol? subProtocol = req?.SubProtocol ?? SubProtocols.FirstOrDefault(); - PeerContext peerContext = (PeerContext)context; - Channel chan = CreateChannel(subProtocol); + ChannelFactory? sf = _factories[subProtocol] as ChannelFactory; - _logger?.LogDebug("Listen {chan} on protocol {sp} with sub-protocols {sf}", chan.Id, subProtocol.Id, _factories[subProtocol].SubProtocols.Select(s => s.Id)); + _logger?.LogAction(nameof(SubListen), chan.Id, subProtocol.Id, sf?.SubProtocols.Select(s => s.Id) ?? Enumerable.Empty()); - _ = subProtocol.ListenAsync(chan.Reverse, _factories[subProtocol], context).ContinueWith(async t => + _ = subProtocol.ListenAsync(chan.Reverse, sf, context).ContinueWith(async t => { if (!t.IsCompletedSuccessfully) { - _logger?.LogError("Listen error {proto} via {chan}: {error}", subProtocol.Id, chan.Id, t.Exception?.Message ?? "unknown"); + _logger?.LogCompletedUnsuccessfully(nameof(SubListen), chan.Id, subProtocol.Id, t.Exception, t.Exception?.Message ?? "unknown"); } - IEnumerable dd = _factories[subProtocol].SubProtocols; - if (!chan.IsClosed) { await chan.CloseAsync(); @@ -80,14 +77,17 @@ public IChannel SubDialAndBind(IChannel parent, IPeerContext context, { IProtocol? subProtocol = req?.SubProtocol ?? SubProtocols.FirstOrDefault(); Channel chan = CreateChannel(subProtocol); + ChannelFactory? sf = _factories[subProtocol] as ChannelFactory; + + _logger?.LogAction(nameof(SubDialAndBind), chan.Id, subProtocol.Id, sf?.SubProtocols.Select(s => s.Id) ?? Enumerable.Empty()); + chan.Bind(parent); - _ = subProtocol.DialAsync(chan.Reverse, _factories[subProtocol], context).ContinueWith(async t => + _ = subProtocol.DialAsync(chan.Reverse, sf, context).ContinueWith(async t => { if (!t.IsCompletedSuccessfully) { - _logger?.LogError("SubDialAndBind error {proto} via {chan}: {error}", chan.Id, subProtocol.Id, t.Exception?.Message ?? "unknown"); + _logger?.LogCompletedUnsuccessfully(nameof(SubDialAndBind), chan.Id, subProtocol.Id, t.Exception, t.Exception?.Message ?? "unknown"); } - if (!chan.IsClosed) { await chan.CloseAsync(); @@ -104,12 +104,16 @@ public IChannel SubListenAndBind(IChannel parent, IPeerContext context, { IProtocol? subProtocol = req?.SubProtocol ?? SubProtocols.FirstOrDefault(); Channel chan = CreateChannel(subProtocol); + ChannelFactory? sf = _factories[subProtocol] as ChannelFactory; + + _logger?.LogAction(nameof(SubListenAndBind), chan.Id, subProtocol.Id, sf?.SubProtocols.Select(s => s.Id) ?? Enumerable.Empty()); + chan.Bind(parent); _ = subProtocol.ListenAsync(chan.Reverse, _factories[subProtocol], context).ContinueWith(async t => { if (!t.IsCompletedSuccessfully) { - _logger?.LogError("SubListenAndBind error {proto} via {chan}: {error}", subProtocol.Id, chan.Id, t.Exception?.Message ?? "unknown"); + _logger?.LogCompletedUnsuccessfully(nameof(SubListenAndBind), chan.Id, subProtocol.Id, t.Exception, t.Exception?.Message ?? "unknown"); } if (!chan.IsClosed) { @@ -129,11 +133,11 @@ public ChannelFactory Setup(IProtocol parent, IDictionary(_serviceProvider); - chan.Id = $"{_parent.Id} <> {subprotocol?.Id}"; - _logger?.LogDebug("Create chan {0}", chan.Id); + chan.Id = $"{_parent.Id} <> {subProtocol?.Id}"; + _logger?.ChanCreated(chan.Id); return chan; } } diff --git a/src/libp2p/Libp2p.Core/LogMessages.cs b/src/libp2p/Libp2p.Core/LogMessages.cs new file mode 100644 index 00000000..4a1c823e --- /dev/null +++ b/src/libp2p/Libp2p.Core/LogMessages.cs @@ -0,0 +1,59 @@ +// SPDX-FileCopyrightText: 2023 Demerzel Solutions Limited +// SPDX-License-Identifier: MIT + +using Microsoft.Extensions.Logging; + +namespace Nethermind.Libp2p.Core; + +internal static partial class LogMessages +{ + [LoggerMessage( + Message = "Read chunk {bytes} bytes", + Level = LogLevel.Trace)] + internal static partial void ReadChunk( + this ILogger logger, + long bytes); + + [LoggerMessage( + Message = "Read enough {bytes} bytes", + Level = LogLevel.Trace)] + internal static partial void ReadEnough( + this ILogger logger, + long bytes); + + [LoggerMessage( + Message = "Write {bytes} bytes", + Level = LogLevel.Trace)] + internal static partial void WriteBytes( + this ILogger logger, + long bytes); + + [LoggerMessage( + Message = "{method} {chan} on protocol {protocols} with sub-protocols {subProtocols}", + Level = LogLevel.Debug)] + internal static partial void LogAction( + this ILogger logger, + string method, + string chan, + string protocol, + IEnumerable subProtocols); + + [LoggerMessage( + Message = "Create chan {chan}", + Level = LogLevel.Debug)] + internal static partial void ChanCreated( + this ILogger logger, + string chan); + + [LoggerMessage( + Message = "{method} error {protocol} via {chan}: {errorMessage}", + Level = LogLevel.Error, + SkipEnabledCheck = true)] + internal static partial void LogCompletedUnsuccessfully( + this ILogger logger, + string method, + string chan, + string protocol, + Exception? exception, + string errorMessage); +}