Phobos.Tracing 2.5.0

Distributed tracing support for Akka.NET ActorSystems.

Install-Package Phobos.Tracing -Version 2.5.0

dotnet add package Phobos.Tracing --version 2.5.0

<PackageReference Include="Phobos.Tracing" Version="2.5.0"/>

paket add Phobos.Tracing --version 2.5.0

Paket is a third-party, open source alternative to the NuGet client.

Release Notes

Phobos 2.5 Minor Release** Phobos 2.5.0 is, once again, a _massive performance upgrade_ over Phobos 2.4.5 and earlier. 62% faster when both tracing and metrics are enabled, in fact. Performance Improvements** We followed more of the same techniques we described in "[How We Made Phobos 2.4's OpenTelemetry Usage 62% Faster](https://petabridge.com/blog/phobos-2.4-opentelemetry-optimizations/)" and were able to move major heavy sources of allocations outside of Phobos' performance critical path. Our throughput in v2.4.5: | Metric | Units / s | Max / s | Average / s | Min / s | StdDev / s | |---------------- |---------------- |---------------- |---------------- |---------------- |---------------- | |TotalCollections [Gen0] | collections | 83.31 | 81.55 | 80.38 | 0.88 | |TotalCollections [Gen1] | collections | 5.80 | 5.08 | 4.27 | 0.49 | |TotalCollections [Gen2] | collections | 2.17 | 1.97 | 1.42 | 0.31 | |[Counter] MessageReceived | operations | 2,173,276.34 | 2,131,567.21 | 2,096,899.11 | 23,842.54 | Here's what our performance looked like in v2.5, in terms of total instrumented throughput: | Metric | Units / s | Max / s | Average / s | Min / s | StdDev / s | |---------------- |---------------- |---------------- |---------------- |---------------- |---------------- | |TotalCollections [Gen0] | collections | 20.43 | 19.65 | 18.86 | 0.48 | |TotalCollections [Gen1] | collections | 7.04 | 5.83 | 4.96 | 0.65 | |TotalCollections [Gen2] | collections | 3.06 | 2.68 | 1.98 | 0.47 | |[Counter] MessageReceived | operations | 3,064,477.84 | 2,994,416.62 | 2,891,043.79 | 53,773.16 | In terms of total throughput, we're looking at an **average improvement of 41% efficiency**. But when it comes to hotpath _memory consumption_, the numbers are even more incredible (you can also tell by looking at the stark difference in GC activity between 2.4.5 and 2.5.0): ``` BenchmarkDotNet v0.13.10, Windows 11 (10.0.22621.3007/22H2/2022Update/SunValley2) 12th Gen Intel Core i7-1260P, 1 CPU, 16 logical and 12 physical cores .NET SDK 8.0.101 [Host] : .NET 7.0.15 (7.0.1523.57226), X64 RyuJIT AVX2 DefaultJob : .NET 7.0.15 (7.0.1523.57226), X64 RyuJIT AVX2 ``` | Method | MessageKind | Mean | Error | StdDev | Req/sec | Gen0 | Allocated | |--------------------------- |------------ |---------:|--------:|--------:|-------------:|-------:|----------:| | **CreateNewRootSpan** | **Primitive** | **139.7 ns** | **2.10 ns** | **1.86 ns** | **7,157,539.53** | **0.0305** | **288 B** | | CreateChildSpan | Primitive | 142.2 ns | 2.35 ns | 2.19 ns | 7,030,112.29 | 0.0305 | 288 B | | CreateChildSpanWithBaggage | Primitive | 147.8 ns | 2.28 ns | 2.13 ns | 6,766,701.91 | 0.0305 | 288 B | | **CreateNewRootSpan** | **Class** | **139.1 ns** | **2.34 ns** | **2.18 ns** | **7,191,051.43** | **0.0305** | **288 B** | | CreateChildSpan | Class | 141.8 ns | 2.03 ns | 1.90 ns | 7,054,363.87 | 0.0305 | 288 B | | CreateChildSpanWithBaggage | Class | 148.6 ns | 1.44 ns | 1.20 ns | 6,731,252.60 | 0.0305 | 288 B | | **CreateNewRootSpan** | **Record** | **141.1 ns** | **2.47 ns** | **2.43 ns** | **7,086,392.57** | **0.0305** | **288 B** | | CreateChildSpan | Record | 141.0 ns | 1.68 ns | 1.57 ns | 7,090,756.01 | 0.0305 | 288 B | | CreateChildSpanWithBaggage | Record | 149.7 ns | 2.62 ns | 2.45 ns | 6,678,880.92 | 0.0305 | 288 B | in 2.4.5 Phobos allocated 288 bytes per span (in this fixed-size test case - real-world values could be much larger.) But in 2.5.0... ``` BenchmarkDotNet v0.13.10, Windows 11 (10.0.22621.3007/22H2/2022Update/SunValley2) 12th Gen Intel Core i7-1260P, 1 CPU, 16 logical and 12 physical cores .NET SDK 8.0.101 [Host] : .NET 7.0.15 (7.0.1523.57226), X64 RyuJIT AVX2 DefaultJob : .NET 7.0.15 (7.0.1523.57226), X64 RyuJIT AVX2 ``` | Method | MessageKind | Mean | Error | StdDev | Req/sec | Gen0 | Allocated | |--------------------------- |------------ |---------:|---------:|---------:|--------------:|-------:|----------:| | **CreateNewRootSpan** | **Primitive** | **59.97 ns** | **0.637 ns** | **0.565 ns** | **16,676,180.98** | **0.0050** | **48 B** | | CreateChildSpan | Primitive | 67.24 ns | 0.943 ns | 0.836 ns | 14,871,155.56 | 0.0050 | 48 B | | CreateChildSpanWithBaggage | Primitive | 77.87 ns | 0.871 ns | 0.814 ns | 12,842,151.57 | 0.0050 | 48 B | | **CreateNewRootSpan** | **Class** | **59.70 ns** | **0.695 ns** | **0.616 ns** | **16,749,521.86** | **0.0050** | **48 B** | | CreateChildSpan | Class | 63.69 ns | 0.715 ns | 0.669 ns | 15,701,818.74 | 0.0050 | 48 B | | CreateChildSpanWithBaggage | Class | 71.53 ns | 0.650 ns | 0.576 ns | 13,979,808.57 | 0.0050 | 48 B | | **CreateNewRootSpan** | **Record** | **56.55 ns** | **0.258 ns** | **0.229 ns** | **17,684,262.41** | **0.0051** | **48 B** | | CreateChildSpan | Record | 64.35 ns | 0.369 ns | 0.288 ns | 15,538,845.63 | 0.0050 | 48 B | | CreateChildSpanWithBaggage | Record | 72.41 ns | 0.655 ns | 0.613 ns | 13,809,634.69 | 0.0050 | 48 B | That same test case now only allocates 48 bytes per span - 83% less memory than we used before. Reduced Noise from `IStash`** We've also made a significant noise control improvement: `IStash` no longer produces separate operations that appear in traces any longer. The `akka.msg.stash` and `akka.msg.unstash` no longer appear as their own distinct `Activity` / `TelemetrySpan` operations during tracing; rather, when stashing and unstashing occur in 2.5 they will be appended as `akka.msg.stash` and `akka.msg.unstash` events on the original `akka.msg.recv <messageType>` operation - and that operation will now remain open until the stashed message is finally unstashed and processed.