Files
romanett b25429bccc Client: cut per-request allocation and CPU in the channel and session; measure the client in the load harness (#4720)
Follows #4707 (replaces #4714, which closed when the #4707 branch was
deleted). Profiling the client process under load showed per-request
allocation spread over the channel write path, the response wait,
per-chunk header encoders and an AES instance per message, plus a stack
walk per service call. This PR removes them and extends the load harness
to measure the client.

## Results

Paired A/B against the #4707 head, the server work now on master (3
alternating rounds, medians, 20 sessions unless noted, workstation GC on
both sides, 24-core machine). Client = the harness process, server = the
reference server child.

| Scenario | Throughput | p50 | p90 | Client CPU / op | Client alloc /
op | Server alloc / op |
|---|---|---|---|---|---|---|
| Read, 1 value | **+21%** (141k → 170k req/s) | −9% | −11% | −13% |
−46% (4.5 → 2.4 KB) | −20% |
| Read, 1 value, ManagedSession | **+18%** | −9% | −12% | −18% | −44% |
−20% |
| Read, 1 value, SignAndEncrypt | **+28%** | −14% | −20% | −24% | −52% |
−26% |
| Read, 1 value, 200 sessions | **+29%** | −11% | −17% | −17% | −46% |
−20% |
| Read, 100 values | +5% | −2% | −3% | −6% | −44% (15.6 → 8.8 KB) | −2%
|
| Read, 100 values, SignAndEncrypt | +8% | −7% | −2% | −2% | −46% | −3%
|
| Write, 100 values | ±0 | ≈ | ≈ | −14% | **−63%** (10.8 → 4.0 KB) | −2%
|
| Browse (Server object) | **+12%** | −7% | −11% | −19% | −17% | −12% |
| Data changes, classic fast callback | ±0 ¹ | ≈ | ≈ | −21% | −10% | −5%
|
| Data changes, classic item events | ±0 ¹ | ≈ | ≈ | ≈ ² | −7% | −5% |
| Data changes, ManagedSession (V2) | ±0 ¹ | ≈ | ≈ | ±0 | −5% | −5% |
| Data changes, SignAndEncrypt | ±0 ¹ | ≈ | ≈ | −22% | −14% | −7% |

¹ Throughput is bounded by the writer rate; latency is dominated by the
100 ms publishing interval. Per notification the client uses about 2 µs
and 170–260 B.
² The client uses 0.2–0.4 cores in the subscription scenarios; the CPU
per notification is within run-to-run noise there.

Client GC pause time in the window drops 38–66% in the Read and Write
scenarios (17% for Browse). About 70% of the remaining client CPU per
small request is kernel time in loopback socket send/receive.

## Changes

- **Activity source**: `Session`, `SessionClientBatched`, the classic
`Subscription` and `ClassicSubscriptionEngine`, and the TCP/HTTPS client
channels resolve their `ActivitySource` once.
`TelemetryExtensions.StartActivity` called
`Assembly.GetCallingAssembly()` (a stack walk) on every service call,
~8% of client CPU.
- **Channel write queue** (`UaSCUaBinaryChannel`, client and server): an
ordered queue drained by one thread-pool writer replaces the per-write
`ContinueWith`/`Unwrap`/trailing continuation chain. The writer is
queued to the issuing thread's local pool queue, like the task
continuation was (queuing it globally cost ~15 µs of p50 in a first
iteration). Successful writes are reported inline instead of through
`Task.Run`; failed writes still go through the pool. The client channel
enters its gate only for a failed write instead of on every write
completion.
- **`TcpByteTransport`**: no linked `CancellationTokenSource` when the
caller's token cannot be cancelled (the channel always passes `None`); a
single-chunk `BufferCollection` uses the `ReadOnlyMemory` send instead
of the vectored `Task<int>` send; `PoolingAsyncValueTaskMethodBuilder`
on .NET 6+ for the receive/send state machines; no closure per vectored
send.
- **`BinaryEncoder.GetNodeIdEncoding`**: `Convert.ToUInt32(uint,
IFormatProvider)` bound to the `object` overload and
`Convert.ToByte(enum, ...)` boxed the enum, two boxes per encoded
NodeId. 44% of the client allocation of a 100-value Read; the server
encodes NodeIds the same way.
- **Symmetric chunk headers**: the 24 header bytes are written and read
with `BinaryPrimitives` instead of a `MemoryStream` +
`BinaryEncoder`/`BinaryWriter` (send) and `BinaryDecoder`/`BinaryReader`
(receive) per chunk. A chunk too short for a field still gets the
decoder's `BadDecodingError`.
- **AES-CBC**: `ChannelToken` keeps one `Aes` per direction, used with
the one-shot `EncryptCbc`/`DecryptCbc` on .NET 6+ (net48 reuses the
instance and creates the transform). Previously every message created an
`Aes`, imported the key (`BCryptImportKey`) and created a transform,
~15% of client CPU with SignAndEncrypt. The instance is taken out of the
token while in use, so concurrent callers never share one. The public
`CryptoUtils` overloads are unchanged.
- **`ChannelAsyncOperation`**: `SendRequestAsync` waits on an internal
task-free completion source instead of `EndAsync`
(`TaskCompletionSource` + `Task` + `WaitAsync` promise + state machine);
`EndAsync` registers cancellation instead of `WaitAsync(ct)`; the
timeout timer uses a static callback; completing with `default(T)`
shares a box.
- **Session keep alive**: every good response called `Timer.Change`
under the session lock, taking the timer queue lock. It now records the
time; the timer callback defers itself to one interval after the last
response, which is when the per-response reset made it fire.

### Behaviour notes
- `TcpByteTransport.SendChunkAsync`/`ReceiveChunkAsync` return pooled
`ValueTask`s on .NET 6+: like any `ValueTask` they must be awaited once.
- A successful write's `HandleWriteComplete` now runs on the writer
instead of a separate pool work item. Overrides outside the stack that
block in it delay later writes on that channel.
- The write itself no longer flows the caller's `ExecutionContext`
(`Activity.Current` is not set inside the transport send).

## Harness (`perf/`)
- `client-process:` and `client-per-op:` result lines; `--trace-side
client` records the harness itself.
- `--client managed` (ManagedSession, V2 engine) and `--callback item`
(classic per-item events).
- Classic fixture sessions no longer request diagnostics in every
response (the server otherwise sends a `DiagnosticInfo` per
notification).
- `ab.sh`: `SCENARIOS`/`ROUNDS`/`OUT`, CRLF tolerant, defaults before
the scenario (a `--sessions 200` scenario silently ran with 20 before);
`client-scenarios.txt`; `ab-summary.ps1` reports client and server
medians.
- README notes two profile traps: `Monitor.Enter_Slowpath` in the
sampled CPU profile without matching contention events (46 in 10 s
here), and allocation ticks over-attributing small objects allocated
after large arrays.

## Testing
- New: `UaSCBinaryChannelWriteQueueTests` (order, one send at a time,
never on the caller's stack, failures reported and later writes still
sent, concurrent writers), `ChannelAsyncOperationWaitTests` (late/early
completion, faults, cancellation, disposal, continuation off the
completing thread, 2000-iteration completion/cancellation race,
timeout), `CryptoUtilsAesCacheTests` (cached = fresh cipher text across
IVs, round trips, concurrent users, token disposal),
`TcpByteTransportTests` single/multi-buffer and cancellable sends,
`SessionKeepAliveTests` keep-alive read exactly one interval after the
last response.
- After merging master: Core Stack 3571 passed, Client 2763 passed, 0
failed.
- Before merging master, net10.0: Core Stack+Security 4680 passed;
Client 2763; Sessions 849 (379 skipped); Server 8391; Subscriptions 643;
all 0 failed.
- Stress Contract+Integration: 5 failures, the same 5 on the unchanged
#4707 head (`CertRotationContractTests`, `GateAndBypassTests`,
`LeaseLifecycleTests`, `RetryBudgetEnforcementTests` reflection seam,
`CertRotationLiveTests`), not caused by this PR.
- net48 build of `UA.slnx` clean; `dotnet format whitespace` clean.

## Not changed (follow-ups)
- Two `recv` calls per chunk (8-byte header, then body). Merging them
needs read-ahead with carry-over, which the transport avoids so that
idle peers do not hold receive buffers.
- `ManagedSession` service wrappers add an async state machine and a
reader lock per call (~200 B).
- Generated responses allocate a discarded `ResponseHeader`
(generator-wide, as noted in #4707).
- Decoded `MonitoredItemNotification` objects and the V2
`DataValueChange[]` per message dominate notification allocation
(`WithPoolNotifications` pools the latter).
- Coalescing queued writes on one channel into one vectored send would
cut syscalls under concurrent requests on a shared channel.

🤖 Generated with [Claude Code](https://claude.com/claude-code)

---------

Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
Co-authored-by: Marc <marcschier@hotmail.com>
Co-authored-by: Marc Schier <marcschier@users.noreply.github.com>
2026-10-10 20:00:33 +02:00

117 lines
5.1 KiB
C#

/* ========================================================================
* Copyright (c) 2005-2025 The OPC Foundation, Inc. All rights reserved.
*
* OPC Foundation MIT License 1.00
*
* Permission is hereby granted, free of charge, to any person
* obtaining a copy of this software and associated documentation
* files (the "Software"), to deal in the Software without
* restriction, including without limitation the rights to use,
* copy, modify, merge, publish, distribute, sublicense, and/or sell
* copies of the Software, and to permit persons to whom the
* Software is furnished to do so, subject to the following
* conditions:
*
* The above copyright notice and this permission notice shall be
* included in all copies or substantial portions of the Software.
* THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
* EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES
* OF MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND
* NONINFRINGEMENT. IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT
* HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY,
* WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING
* FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR
* OTHER DEALINGS IN THE SOFTWARE.
*
* The complete license agreement can be found here:
* http://opcfoundation.org/License/MIT/1.00/
* ======================================================================*/
using System;
using System.Threading;
using System.Threading.Tasks;
using Opc.Ua.Client.Subscriptions;
using Opc.Ua.Client.Subscriptions.MonitoredItems;
namespace Opc.Ua.Perf.ServerLoadHarness
{
/// <summary>
/// Waits for one managed subscription and its monitored items to be ready for measurement.
/// </summary>
internal sealed class SubscriptionSetup
{
/// <summary>
/// Creates a setup observer using the supplied clock or the system clock.
/// </summary>
internal SubscriptionSetup(TimeProvider? timeProvider = null)
{
m_timeProvider = timeProvider ?? TimeProvider.System;
}
/// <summary>
/// Retains the first subscription failure, including failures reported before waiting starts.
/// </summary>
internal void OnStateChanged(SubscriptionState state)
{
if (state is SubscriptionState.Error or SubscriptionState.Deleted)
{
Interlocked.CompareExchange(ref m_failureState, (int)state, 0);
}
}
/// <summary>
/// Waits up to one minute for the subscription and all of its items to be created.
/// </summary>
/// <exception cref="ServiceResultException">A monitored item was rejected.</exception>
/// <exception cref="InvalidOperationException">The subscription failed or was deleted.</exception>
/// <exception cref="TimeoutException">Setup did not complete before the deadline.</exception>
/// <exception cref="OperationCanceledException">The caller cancelled setup.</exception>
internal async Task WaitForReadyAsync(ISubscription subscription, CancellationToken ct)
{
ct.ThrowIfCancellationRequested();
using var timeout = m_timeProvider.CreateCancellationTokenSource(TimeSpan.FromMinutes(1));
using var stop = CancellationTokenSource.CreateLinkedTokenSource(ct, timeout.Token);
try
{
while (true)
{
stop.Token.ThrowIfCancellationRequested();
var state = (SubscriptionState)Volatile.Read(ref m_failureState);
if (state is SubscriptionState.Error or SubscriptionState.Deleted)
{
throw new InvalidOperationException(
$"Managed subscription setup failed with state {state}.");
}
bool ready = subscription.Created;
foreach (IMonitoredItem item in subscription.MonitoredItems.Items)
{
ServiceResult error = item.Error;
if (ServiceResult.IsBad(error))
{
throw new ServiceResultException(
error.StatusCode,
$"Monitored item '{item.Name}' failed during subscription setup: {error}");
}
ready &= item.Created;
}
if (ready)
{
return;
}
await m_timeProvider.Delay(TimeSpan.FromMilliseconds(50), stop.Token).ConfigureAwait(false);
}
}
catch (OperationCanceledException exception) when (timeout.IsCancellationRequested &&
!ct.IsCancellationRequested)
{
throw new TimeoutException("Managed subscription setup did not complete within one minute.", exception);
}
}
private readonly TimeProvider m_timeProvider;
private int m_failureState;
}
}