Apollo3zehn / FluentModbus

Lightweight and fast client and server implementation of the Modbus protocol (TCP/RTU).
MIT License
211 stars 72 forks source link

feat: RTU communication message Log #117

Open zh3305 opened 4 months ago

zh3305 commented 4 months ago

            /* create Modbus RTU client */
            var client = new ModbusRtuClient();
            client.Logger = loggerFactory.CreateLogger("Client");

image

Apollo3zehn commented 4 months ago

Hi, thanks for your PR. I understand the reason why you would like to see it implemented but I have some concerns regarding performance. Specifically the following LOCs will put a large burden on the garbage collector:

  1. LogFrame("Rx",_frameBuffer.Buffer.AsMemory()[..frameLength].ToArray()); Here the problem is that on every single frame received a new array is being allocated (ToArray()), even if the log level is > Trace.

  2. Logger.LogTrace($"{prefix}: {string.Join(" ", frame.Select(b => b.ToString("X2")))}"); This line is full of allocations:

    • 1x string.Join(...)
    • 1x frame.Select(...) (not obvious, but I read somewhere that LINQ is not allocation-free)
    • many string allocations (b.ToString()), i.e. 1 allocation per frame byte
    • And in general, log messages should use the syntax Logger.LogTrace("string with {Value}, value") instead of Logger.LogTrace($"string with {Value}") to avoid allocations when the log level is > Trace.

I am afraid that I cannot merge your PR with these many allocations as FluentModbus focusses entirely on performance, hence the heavy use of Span<T> everywhere to avoid allocations.

I also have no immediate solution to avoid these allocations. The only workaround would be to put preprocessor directives around the allocation-heavy logging code like this

#if DEBUG
    LogFrame(...);
#endif

This would mean the code will not become part of the Nuget package but would be available when cloning this repo and directly referencing it. I am not sure if this would be a practical solution, maybe you can share your thoughts on this. Thanks!

zh3305 commented 4 months ago

Thank you for your feedback. I appreciate your concerns regarding performance.

With regard to log performance, I propose implementing a toggle switch named bool IsLogFrameData to allow dynamic configuration of logging output. This will ensure that logging overhead is minimized when not required.

For the performance issue related to converting bytes to hexadecimal, I have referenced an optimized solution found at https://gist.github.com/antoninkriz/915364de7f264dd14a572936abd5228b. This approach aims to minimize allocations and improve conversion speed.For non-.NET 5 environments, in this Stack Overflow post: https://stackoverflow.com/a/24343727/3161322. The benchmark results indicate significant performance gains, especially in terms of allocation reduction.

Here is a summary of the benchmark results:

Method Runtime Mean Error StdDev Median Ratio RatioSD Gen0 Gen1 Allocated Alloc Ratio
bitConverter .NET 8.0 90.62 ns 1.246 ns 1.104 ns 90.84 ns 0.58 0.01 0.0353 - 296 B 0.54
bitConverter .NET Framework 4.8 155.24 ns 0.853 ns 0.713 ns 155.04 ns 1 0 0.0865 0.0002 546 B 1
ToHexString2 .NET 8.0 36.47 ns 0.499 ns 0.467 ns 36.56 ns 0.69 0.02 0.02 - 168 B 0.99
ToHexString2 .NET Framework 4.8 52.00 ns 0.453 ns 0.905 ns 51.77 ns 1 0 0.0268 0.0001 169 B 1
hexConverter .NET 8.0 64.20 ns 0.782 ns 0.653 ns 64.22 ns 0.4 0.01 0.02 - 168 B 0.99
hexConverter .NET Framework 4.8 162.07 ns 1.309 ns 1.224 ns 161.64 ns 1 0 0.0267 0.0002 169 B 1
ByteArrayToHexViaLookup32 .NET 8.0 68.88 ns 1.423 ns 1.262 ns 69.14 ns 0.35 0.01 0.0401 - 336 B 1
ByteArrayToHexViaLookup32 .NET Framework 4.8 197.11 ns 1.709 ns 1.515 ns 197.31 ns 1 0 0.0534 0.0002 337 B 1
ByteArrayToHexViaLookup32Unsafe .NET 8.0 38.57 ns 0.817 ns 1.474 ns 37.76 ns 0.77 0.03 0.0401 - 336 B 1
ByteArrayToHexViaLookup32Unsafe .NET Framework 4.8 51.50 ns 0.307 ns 0.272 ns 51.39 ns 1 0 0.0535 0.0001 337 B 1

Thank you for your valuable input!