Files
Joseph Doherty 12dffb9254
v2-ci / unit-tests (pull_request) Waiting to run
docs: retain reviewed memory investigation and prospective gate limits
2026-11-10 14:21:57 -05:00

287 lines
18 KiB
Markdown
Raw Permalink Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# SDK 2 lifecycle memory investigation
The required two-hour server lifecycle gate failed on macOS and Linux. The RSS
limit remains **cycle-3 baseline + 128 MiB**; retained managed memory remains
+64 MiB and descriptors +32. No threshold, production code, certificate provider,
or session factory was changed by this investigation. These controls do not
replace the full gate. Issue #799 remains open.
## Preserved full-workload failures
| Run | Cycles / restarts | Observation time | RSS / limit (bytes) | Outcome |
|---|---:|---:|---:|---|
| macOS `fa823378` | 250 / 62 | 1045.53 s | 365,215,744 / 363,331,584 | Failed |
| macOS `e135b7c9` profile reproduction | 245 / 61 | 1024.14 s | 368,656,384 / 363,053,056 | Failed |
| Linux full harness, recorded build `38098ce142ab8c382825aa754e0758071dd3a46b` | 248 / 61 | 903.508 s | 353,931,264 / 351,850,496 | Failed |
| macOS `6b2d4b81` bounded profile | 432 / 108 | 1807.479 s | First rejection: 364,199,936 / 363,266,048 | Failed; first assertion rethrown |
The last macOS row requested 1,800 seconds. It first rejected RSS at cycle 253 /
1055.482 seconds, continued recording explicitly rejected observations, then
threw the original assertion before any completion record. Its final observation
was RSS 380,059,648, live managed 41,364,096, GC committed 37,060,608, JIT
compilations 81,535, descriptors 200, and zero sessions, subscriptions, monitored
items, browse/history continuation points, and PKI descriptors. SDK cached stores
remained two during operation. The test runner returned exit 1; the nonzero-execution guard passed (exit 0),
with one executed test and zero skipped tests. There is no passing two-hour result here.
The first macOS run's reported PKI descriptor zero is invalid: `/var` and
`/private/var` aliases were not canonicalized. Corrected positive-handle and timeout
controls passed before subsequent profiles. Global descriptor counts and the RSS
failure itself were independent of that defect. A Shouldly source-expression
message incorrectly names `Descriptors` in the RSS failure; the actual numeric
comparison is RSS, as retained before the assertion.
## What the controls demonstrate
`LifecycleControl.cs` uses unchanged published product DLLs and public APIs for
both SDK generations. It opens two real encrypted **opc.tcp** sessions with
Basic256Sha256 / SignAndEncrypt, resolves namespace URIs, reads/writes Int32 and
Int16[] values, creates/deletes two data monitored items, abandons a browse
continuation, closes sessions, and restarts a server with an active subscription
every four cycles against the same task-owned PKI. Public session/subscription
counts must return to zero. It has no historian, revocation, surgical-rebuild,
paused-network, or private continuation-store coverage. It is a diagnostic subset,
not TLS and not the full soak workload.
The original DLLs are the immutable 1.5.378.182 baseline publication associated
with `83ed880e`; its assembly version alone is 1.5.378.0 and does not identify the
patch. The candidate uses SDK 2.0.1 and the server implementation from `fa823378`.
Neither baseline nor candidate product code was rebuilt for these controls.
The controls were compiled once for each reference set, then those exact control
artifacts were used on both operating systems. Selected DLL and input-artifact
hashes are in `evidence.json`. Neither reference set's principal SDK/server DLLs
has a managed native/ReadyToRun header.
| Ten-minute matched subset | Cycles / restarts | Final RSS | Change from cycle 3 | Final managed / change | Final JIT compilations |
|---|---:|---:|---:|---:|---:|
| macOS original | 212 / 53 | 330,301,440 | +121,683,968 | 271,168,424 / +169,990,456 | 28,066 |
| macOS SDK2 | 200 / 50 | 302,170,112 | +95,862,784 | 44,569,584 / +295,120 | 62,608 |
| Linux original | 249 / 62 | 384,950,272 | +176,836,608 | 147,139,568 / +99,356,752 | 28,321 |
| Linux SDK2 | 259 / 64 | 390,844,416 | +194,183,168 | 19,561,120 / +736 | 71,529 |
Both ten-minute controls exited zero because their lifecycle checks passed;
`fullGate=false` is explicit. They do **not** enforce the full harness memory
assertions. In particular, both Linux subset RSS deltas exceed 128 MiB and the
original retains managed memory/timers. These observations do not waive either
failed full gate. They are not proof of an SDK1 defect or an SDK2 improvement.
Both control branches explicitly delete subscriptions, close normal sessions,
and dispose sessions/subscriptions. Parked resources intentionally encounter
server shutdown and are then disposed. Each version calls its unchanged product
host's DisposeAsync. The baseline host only calls ApplicationInstance.StopAsync;
that original ApplicationInstance exposes no disposal interface. The SDK2 branch
also uses its new ApplicationInstance.DisposeAsync ownership API. Per-connection
DefaultTelemetry factories are left to the same ownership pattern on both
branches, separately probed above. Thus measured original growth belongs to this
published-product/fixture lifecycle combination; its allocation owner has not
been isolated. These are one matched run per platform, concurrent processes,
with different runtime versions; they are not performance distributions.
The thirty-minute Linux comparison uses the same immutable artifacts and image,
fresh independent fixtures, and SDK2 certificate allocation tracking enabled
before the first certificate (the same environment is passed to both versions).
Both finished with exit zero and `fullGate=false`:
| Thirty-minute Linux subset | Cycles / restarts | Final RSS | Final live managed | GC committed | JIT compilations | Active timers |
|---|---:|---:|---:|---:|---:|---:|
| Original | 736 / 184 | 540,057,600 | 342,626,200 | 408,399,872 | 29,177 | 926 |
| SDK2 | 768 / 192 | 334,180,352 | 19,248,984 | 42,983,424 | 72,087 | 19 |
Observed runtime was 1802.542 seconds original / 1804.523 seconds SDK2. The SDK2
RSS fell from 390,782,976 at the 632.7-second checkpoint to 334,180,352 at the last
observation; live managed stayed near 20 MB. After disposal and final collection,
SDK2 wrapper counters were 19,272 created = 19,272 disposed, with zero live or
unreachable-undisposed wrappers under enabled tracking. These finite results
support post-transition saturation of this subset, not a two-hour full-workload
pass or a guarantee of indefinite stability.
### Native and runtime observations
- During the macOS bounded profile, `Security::AppleDatabase` counts increased
from 278 at cycle 52 / 211 seconds to 1,953 at cycle 370 / 1546 seconds. These
native objects continued accumulating while managed memory stayed near 40 MiB.
- The single-owner certificate probe makes a self-signed RSA fixture in memory,
then disposes each of 1,000 copies/imports. On macOS, public-only and
shared-handle copies leave AppleDatabase at 2; PFX imports and SDK
`Certificate.AsX509Certificate2` private-key copies grow it from 2 to 1,002.
A separate PFX process retained that count through a 180-second idle hold.
`Certificate.From(original)` owns the original; the checked-in control has no
second owner. All four corrected single-owner modes were rerun successfully.
- The same isolated Linux probe ended at approximately 49 MB RSS for public or
shared copies, 61 MB for PFX imports, and 69 MB for the SDK copy. Those are
endpoint RSS observations including different JIT/GC costs, not evidence of a
Linux native-object leak or a complete attribution.
- SDK2 public certificate counters after the Linux ten-minute lifecycle run were
6,495 created = 6,495 disposed. A separate stack-tracked macOS lifecycle run
ended 591 = 591, zero live and zero unreachable-undisposed wrappers. Allocation
tracking is opt-in; empty internal reports without that opt-in are not proof.
- The Linux ten-minute native snapshots show SDK2 JIT `doublemapper` resident
mappings increasing from about 65.4 to 106.7 MiB, anonymous writable mappings
from 84.6 to 121.3 MiB, and `[heap]` around 19.2 MiB. Original JIT mappings were
about 33.3 to 37.7 MiB. Mapping totals are descriptive categories, not exclusive
object allocations: anonymous memory also contains GC regions, stacks, and
native allocator arenas. RSS includes file/shared pages and can fall with
reclamation. JIT counters are cumulative compilations, not unique live methods.
- 10,000 disposed versus undisposed `DefaultTelemetry` factories ended at similar
RSS (~63.4 MB) and live managed memory (~0.43 MB), with no timer growth. This
does not justify changing host telemetry ownership to fix this failure.
Exact SDK tag source shows private-key PFX copying in nonvirtual
`Certificate.AsX509Certificate2`. A 60-second macOS sampled-thread-time trace
instead found the dominant sampled import path through
`CertificateIdentifierResolver.LoadPrivateKeyCoreAsync` →
`DirectoryCertificateStore.LoadPrivateKeyAsync` → `X509CertificateLoader.LoadPkcs12`.
Inclusive sampled thread-time was about 4.79 seconds for store load and 2.99 seconds
for PKCS12, versus 8.5 milliseconds for AsX509. These are neither exclusive CPU
costs nor call counts. ApplicationInstance already normalizes its validation
input to public DER. The validation copy delegate is internal, the manager sealed,
and no safe narrow application copy-policy seam was identified. Changing session
factory, certificate exportability, or key storage would alter behavior and was
not used as a workaround.
A major JIT/RSS step appeared near 60–64 restarts in several workloads. This is a
hypothesis about runtime/code-cache warmup, not a finding that all RSS growth is
benign. A separate read-only EventPipe attachment observed the thirty-minute
Linux candidate around that transition using `Microsoft-Windows-DotNETRuntime`,
Verbose, keywords `0x18` (Loader + JIT), no rundown, 180 seconds. The transition was UTC 18:51:02.049–18:54:02.062. Factory JIT events
occurred UTC 18:52:48.249–18:53:21.434: 6,690 distinct method tokens from one
module, each once. The module is Opc.Ua.Core.Types.dll; metadata declares 8,442
static methods on OpcUaExtensions. The observed set is a subset, so this does
not prove every possible factory or the complete canonical workload is warmed.
Method-load events totalled 51,327,536 native code bytes, including 51,161,724
OptimizedTier1 bytes and 49,141,484 bytes in generated factories. Only 50
reflection InvokeStub JIT starts occurred; the transition trace reports zero lost events. MethodSize sums count loaded code
versions, not resident/PSS allocation bytes. An additional 180-second attachment
after the transition checks continuing factory compilation. The second attachment (UTC 19:01:44.116–19:04:44.127) recorded 85 JIT starts,
zero lost events, zero Opc.Ua starts, zero generated-factory starts, and zero generated-factory
loaded bytes. Only 18 ordinary Tier1 method loads (5,720 bytes) and 20
instrumented Tier1 loads (5,800 bytes) occurred. This supports a finite generated
factory burst in the observed subset; it does not prove complete canonical
workload saturation. The capture API's default circular-buffer capacity was 256 MiB; that is a
capacity setting, not measured resident overhead. Attachments can allocate event
buffers and perturb execution. Both prior full failures and the ten-minute
control were uninstrumented by these JIT attachments, and the thirty-minute final
interval is unattached. No captured native-code byte total is claimed to equal an
RSS delta. Raw traces/heaps are not committed.
## Reproduce the diagnostic subset
Requires Python 3 and .NET 10. `run.py` references existing DLL directories,
compiles only the control, records SHA-256 provenance, and creates a fresh local
artifact directory. First reference directory wins duplicate filenames. Use the
actual baseline publications, rather than restoring a different package version.
No production project or package file is changed.
```bash
python3 scripts/validation/opcua-lifecycle-memory/run.py lifecycle \
--references "$baselineHostDlls" --references "$baselineClientDlls" \
--output /tmp/opcua-memory-original --seconds 600
python3 scripts/validation/opcua-lifecycle-memory/run.py lifecycle --sdk2 \
--references "$candidateDlls" --output /tmp/opcua-memory-sdk2 --seconds 600 \
--certificate-tracking
```
Fixture credentials are generated in the runner environment and not logged.
PKI material stays under each local `private-fixture` directory. Do not publish
those directories or unredacted process/native logs. These controls grant a
fixture user WriteOperate and auto-accept task-owned certificates; they are
local test fixtures, not deployment configurations.
For a matched Linux pair, first build both with `--build-only` into fresh
`/tmp/opcua-memory-original` and `/tmp/opcua-memory-sdk2` output directories, then:
```bash
python3 scripts/validation/opcua-lifecycle-memory/linux_pair.py \
--baseline /tmp/opcua-memory-original/bin/Release/net10.0 \
--candidate /tmp/opcua-memory-sdk2/bin/Release/net10.0 \
--output /tmp/opcua-memory-linux-pair --seconds 1800 \
--image sha256:b04611ee9e1b7d36797012ed921962c57189cb4dbb3dff12afb8e158110f293b
```
The runner uses separate task-owned `--network none` containers, fresh PKI,
read-only executable mounts, bounded shutdown, and periodic read-only `/proc`
snapshots. It records child and container exit statuses independently. The image
is Ubuntu 24.04 arm64, .NET SDK 10.0.103 / runtime 10.0.3. The Mac runs used
macOS 26.5.2 arm64, SDK 10.0.403 / runtime 10.0.14. Runtime and OS differences are
explicit; do not attribute all cross-platform differences to SDK code.
On macOS, run each certificate mode with a fresh output directory:
```bash
python3 scripts/validation/opcua-lifecycle-memory/run.py certificate --sdk2 \
--references "$candidateDlls" --output /tmp/opcua-memory-pfx --mode pfx
```
Other modes are `sdk-copy`, `public`, and `shared-copy`. The last intentionally
uses the old copy constructor by reflection as a diagnostic control. It is not
proposed production code. The control exports no fixture key/certificate data.
`TelemetryControl.cs` is available through `run.py telemetry --sdk2` with modes
`dispose` or `undisposed`. `summarize.py` emits Linux mapping categories without
file paths from local `*-smaps.txt` files. All controls are opt-in and outside the
ordinary solution/test graph.
Optional trace reproduction uses the installed dotnet-trace 9.0.661903 managed
libraries, without adding a product dependency:
```bash
python3 scripts/validation/opcua-lifecycle-memory/build_trace_tools.py \
--libraries "$diagnosticToolLibraries" --output /tmp/opcua-memory-trace-tools
# Run capture in the same process namespace / user as the task-owned target.
dotnet /tmp/opcua-memory-trace-tools/capture/bin/Release/net10.0/capture.dll \
"$targetPid" 180 /tmp/opcua-memory-local.nettrace
dotnet /tmp/opcua-memory-trace-tools/summary/bin/Release/net10.0/summary.dll \
/tmp/opcua-memory-local.nettrace > /tmp/opcua-memory-method-summary.json
```
Capture is read-only and opt-in; raw traces remain local. The summary exports
static method names and aggregate counts rather than certificate identities,
arguments, or process mappings. The original transition parser also retained
method tokens/modules locally to cross-check name-key uniqueness.
## Prospective saturation experiment (not executed)
The observed finite factory burst supports a separately labeled readiness
experiment; it does not authorize moving the acceptance baseline. A reviewed
candidate proposal is exactly 384 canonical lifecycle cycles / 96 every-four-cycle
restarts, then one fixed settling cycle, all within 1,800 seconds. No early finish,
extension, or RSS-selected endpoint is permitted. Both fixed readiness windows
321–352 and 353–384 must contain zero generated-factory JIT/method-load events, zero SDK assembly
loads, and zero lost events. Other JIT/native-code totals remain review evidence,
not a claim that every runtime path is warmed. Trace capture is bounded and identical for both versions, then
detached/drained before the settling cycle. Ownership, FD, PKI, store, and logical
resource checks remain active throughout; original cold budget rejections remain
recorded. Any later full gate requires at least 7,200 additional seconds after a
prospectively approved baseline. No such warmed full gate has been run here.
The count is beyond the observed 60–64-restart transition and projects to about
1,606 seconds from the Mac canonical run, but completion within the fixed cutoff
is not guaranteed under load. Failure to complete or satisfy readiness is a failed
experiment, not permission to extend. The full canonical test currently depends
on SDK2 value APIs and read-only private SDK2 continuation/store instrumentation.
An original-SDK adapter proving identical history, revocation, surgical-edit,
and stalled-network operation counts is a prerequisite for a matched canonical
experiment; the public subset does not provide that proof. Continued Mac native
inventory growth remains an independent unresolved gate, even if JIT saturates.
## Evidence and limits
`evidence.json` contains sanitized numeric endpoints, native inventory counts,
and hashes of retained diagnostic inputs. Full artifacts remain in the originating
worktrees or `/tmp/opcua2-rss-investigation`; no PKI, certificate identifiers,
credentials, raw traces, unredacted heap/process dumps, or complete test logs are
checked in. Existing failures were preserved untouched.
Supported progress is a reproduced RSS failure, bounded logical/managed
inventories in SDK2, demonstrated macOS PFX native retention, and measured
cross-platform JIT/anonymous-memory growth. A complete allocation attribution and
safe production correction remain unresolved. The server two-hour gate remains
failed; a separate long-running client-only process is a different scope.
Package verification: baseline and candidate control builds, both optional trace
tools, and certificate/telemetry controls built with zero warnings/errors. Local
control smoke runs and the fresh Linux pair smoke exited zero. Python compilation
and whitespace checks passed. One reused-output smoke failed because a manual
incremental build used a different `/tmp` path alias and its runtimeconfig was
missing; fresh canonical outputs passed, and the Linux runner now rejects an
incomplete output directory before launch. These smoke checks validate tooling
only and do not substitute for either long run.