Observability
EncDotNet.S100 is instrumented end-to-end with the standard .NET diagnostic primitives so a performance spike — or any production deployment — can see what the libraries and the viewer are doing without changing code.
| Concern | API used in the libraries | Default behaviour |
|---|---|---|
| Logs | Microsoft.Extensions.Logging.Abstractions ILogger<T> |
NullLogger<T> when no ILoggerFactory is supplied. |
| Traces | System.Diagnostics.ActivitySource |
Inert (StartActivity returns null) until something subscribes. |
| Metrics | System.Diagnostics.Metrics.Meter |
Inert until a MeterListener subscribes. |
The viewer composes these into an OpenTelemetry pipeline that exports via OTLP, so any modern collector — .NET Aspire dashboard, Jaeger, Prometheus + Tempo + Loki, the OpenTelemetry Collector, etc. — can ingest the data without adapter code.
Naming conventions
- One static
Telemetryclass per library exposingActivitySource,Meter, and instrument fields. - ActivitySource / Meter names mirror the assembly name, e.g.
EncDotNet.S100.Datasets.S101,EncDotNet.S100.Renderers.Mapsui,EncDotNet.S100.Viewer. - Activity / metric / tag names are lowercase dotted, namespaced
under
s100.(s100.dataset.open,s100.pipeline.vector.process,s100.hdf5.read.bytes,s100.viewport.zoom). - Tag-key constants live in
EncDotNet.S100.Diagnostics.TelemetryTags(in the Core library).
Span tree (typical viewer command)
s100.viewer.command (kind=Internal, command="dataset.open")
└─ s100.dataset.open
├─ s100.exchangeset.parse
├─ s100.featurecatalogue.parse
├─ s100.hdf5.file.open
├─ s100.hdf5.open{kind=group|dataset} (× N)
└─ s100.hdf5.dataset.read (× N)
└─ s100.pipeline.vector.process [gc.gen0/1/2.delta tags]
├─ s100.pipeline.vector.stage.feature_xml
├─ s100.pipeline.vector.stage.rule_select
├─ s100.pipeline.vector.stage.xslt
│ └─ s100.xslt.transform{rule=…} (× N)
├─ s100.pipeline.vector.stage.lua
│ └─ s100.lua.execute
├─ s100.pipeline.vector.stage.assemble
├─ s100.pipeline.vector.stage.viewing_groups
└─ s100.pipeline.vector.stage.sort
└─ s100.pipeline.coverage.process [gc.gen0/1/2.delta tags]
├─ s100.pipeline.coverage.stage.resolve
└─ s100.pipeline.coverage.stage.read
└─ s100.render.frame
└─ s100.render.coverage.frame
└─ s100.asset.read{kind=file|zip} (× N)
└─ s100.xslt.compile{rule=…} (× N, per catalogue)
The Lua per-rule activity is gated on listener subscription so a
busy ENC does not flood the trace pipeline. Rule volume is captured
instead by the s100.lua.rule.invoke.count counter.
GC delta tags (gc.gen0.delta, gc.gen1.delta, gc.gen2.delta) on
pipeline parent spans are process-wide GC.CollectionCount deltas —
useful for orders-of-magnitude comparisons, not exact attribution.
Metrics catalogue
Pipeline metrics (EncDotNet.S100.Core)
| Instrument | Type | Unit | Tags |
|---|---|---|---|
s100.pipeline.duration |
histogram | ms |
s100.pipeline.stage, s100.product |
s100.pipeline.stage.duration |
histogram | ms |
s100.pipeline.stage |
s100.pipeline.stage.instructions.count |
histogram | {instructions} |
s100.pipeline.stage |
s100.pipeline.features.in |
histogram | {features} |
s100.product |
s100.pipeline.drawinginstructions.out |
histogram | {instructions} |
s100.product |
s100.coverage.cells |
histogram | {cells} |
s100.product |
s100.xslt.transform.duration |
histogram | ms |
s100.xslt.rule |
s100.xslt.compile.duration |
histogram | ms |
s100.xslt.rule |
Asset I/O metrics (EncDotNet.S100.Core)
| Instrument | Type | Unit | Tags |
|---|---|---|---|
s100.asset.read.duration |
histogram | ms |
s100.asset.kind |
s100.asset.bytes.read.count |
counter | By |
s100.asset.kind |
HDF5 metrics (EncDotNet.S100.Hdf5.PureHdf)
| Instrument | Type | Unit | Tags |
|---|---|---|---|
s100.hdf5.read.bytes |
counter | By |
— |
s100.hdf5.read.duration |
histogram | ms |
— |
Lua metrics (EncDotNet.S100.Datasets.S101)
| Instrument | Type | Unit | Tags |
|---|---|---|---|
s100.lua.execute.duration |
histogram | ms |
— |
s100.lua.features.count |
histogram | {features} |
— |
s100.lua.instructions.emitted.count |
histogram | {instructions} |
— |
s100.lua.rule.invoke.count |
counter | {calls} |
s100.lua.rule, s100.result |
s100.lua.rule.invoke.duration |
histogram | ms |
s100.lua.rule |
Mapsui renderer metrics (EncDotNet.S100.Renderers.Mapsui)
| Instrument | Type | Unit | Tags |
|---|---|---|---|
s100.render.frame.duration |
histogram | ms |
— |
s100.render.instructions.processed.count |
histogram | {instructions} |
— |
s100.render.styles.applied.count |
histogram | {styles} |
— |
s100.symbol.resolve.duration |
histogram | ms |
s100.symbol.result, s100.product |
s100.symbol.cache.hit.count |
counter | {hits} |
s100.product |
s100.symbol.cache.miss.count |
counter | {misses} |
s100.product |
s100.pattern.cache.hit.count |
counter | {hits} |
s100.product |
s100.pattern.cache.miss.count |
counter | {misses} |
s100.product |
s100.render.metatile.rasterize.duration |
histogram | ms |
— |
s100.render.metatile.slice.duration |
histogram | ms |
— |
s100.render.metatile.tiles |
histogram | {tile} |
— |
s100.render.metatile.jobs |
counter | {job} |
— |
s100.render.metatile.fallbacks |
counter | {fallback} |
reason |
s100.render.tile.rasterize.duration |
histogram | ms |
— |
s100.render.tile.cold.latency |
histogram | ms |
— |
s100.render.tile.visible.queue.depth |
histogram | {tile} |
— |
s100.render.tile.speculation.deferred |
counter | {worker} |
priority |
s100.render.tile.disk.write_queue.depth |
histogram | {tile} |
— |
s100.render.tile.disk.write_queue.discarded |
counter | {tile} |
reason |
Metatile metrics are emitted only when S100_VECTOR_TILE_METATILE=1 (or the
matching viewer setting is enabled). rasterize.duration is the undivided
union-job time, slice.duration is the copy cost, and tiles measures achieved
batch density. The fallback reason is sparse, disk, scamin, dimension,
or scale (when integer pixel geometry cannot preserve the independent-tile
projection at a fractional device scale). Existing
s100.render.tile.rasterize.duration remains comparable between arms: a
batched job records its total elapsed time divided across the logical tiles it
produced.
s100.render.tile.speculation.deferred counts predicted or cross-band worker
admission attempts rejected while any layer still has visible cold work. A
non-zero count confirms that process-wide visible-first scheduling is actively
protecting the current viewport; sustained growth after the visible queue
drains indicates stale active-layer registration.
When tracing is enabled, the tiled renderer also emits an opt-in
s100.render.tile.job span for each worker job. Child spans separate
disk_read, rasterize, and publish. Job tags include tile keys,
visible/predicted/cross-band priority, queue wait, active worker counts, cache
outcome, viewport epoch, stale/published counts, stale-before-raster counts,
and persistence enqueue results; raster spans include candidate paint operation
count and output dimensions.
Persistent cache writes run independently on a bounded, low-priority writer
after tile publication. Root s100.render.tile.cache.persist spans describe
that background work, with child cache.encode and cache.file_write spans.
The byte budget is enforced from an in-memory LRU index inside
cache.file_write, so no span enumerates the cache directory; it is rescanned
only on first write, every ten minutes, or after an external deletion (such as
"Clear caches") is noticed. Queue overflow and duplicate requests are best-effort
discards rather than render-worker backpressure. The discard reason may also
be stale when a queued tile leaves the current viewport before snapshot,
encoding, or atomic file commit. These spans are inert unless an
ActivityListener subscribes, so ordinary viewer runs do not allocate trace
records.
Use perfreport tile-report to rank slow jobs and attribute their end-to-end
latency (first visible enqueue through publish):
dotnet run --project tools/EncDotNet.S100.PerfReport -- \
tile-report /tmp/viewer-stress/tiles.jsonl --out /tmp/viewer-stress/tiles.md
Viewer paints taking at least 50 ms also emit an
s100.map.paint.slow span. Its tags split the whole paint into summed
instrumented style-renderer time and an uninstrumented remainder, and include
the paint sequence and draw-call count. The sequence and completion timestamp
match get_render_stats.window.slowestFrame, allowing a frame outlier to be
correlated with tile jobs, persistence, and runtime traces.
Tiled-layer composites taking at least 50 ms emit an
s100.render.tile.composite.slow span tagged with the layer name, time waiting
for the layer-state lock, time spent while holding it, cold exposure, and
visible queue depth. This distinguishes compositor lock contention from
expensive cache/GPU work inside the critical section.
Skia renderer metrics (EncDotNet.S100.Renderers.Skia)
| Instrument | Type | Unit | Tags |
|---|---|---|---|
s100.render.coverage.frame.duration |
histogram | ms |
— |
s100.coverage.cells.processed.count |
histogram | {cells} |
— |
Viewer metrics (EncDotNet.S100.Viewer)
| Instrument | Type | Unit | Tags |
|---|---|---|---|
s100.viewer.command.duration |
histogram | ms |
s100.viewer.command |
Cache counters
Every cache that lives between the spec catalogues, dataset processors,
and the renderer emits a hit / miss counter so the audit-recommended
PR-CACHE-7 visibility is available out of the box. All counters are
plain Counter<long> with value 1 per event so a histogram of the
counter directly gives a hit / miss rate.
| Instrument | Source | Unit | Tags |
|---|---|---|---|
s100.symbol.cache.hit.count |
EncDotNet.S100.Renderers.Mapsui |
{hits} |
s100.product |
s100.symbol.cache.miss.count |
EncDotNet.S100.Renderers.Mapsui |
{misses} |
s100.product |
s100.pattern.cache.hit.count |
EncDotNet.S100.Renderers.Mapsui |
{hits} |
s100.product |
s100.pattern.cache.miss.count |
EncDotNet.S100.Renderers.Mapsui |
{misses} |
s100.product |
s100.portrayal.cache.hit.count |
EncDotNet.S100.Portrayals |
{hits} |
s100.product, s100.asset.kind |
s100.portrayal.cache.miss.count |
EncDotNet.S100.Portrayals |
{misses} |
s100.product, s100.asset.kind |
s100.lua.source.cache.hit.count |
EncDotNet.S100.Portrayals |
{hits} |
s100.product |
s100.lua.source.cache.miss.count |
EncDotNet.S100.Portrayals |
{misses} |
s100.product |
s100.featurecatalogue.cache.hit.count |
EncDotNet.S100.Features |
{hits} |
s100.product |
s100.featurecatalogue.cache.miss.count |
EncDotNet.S100.Features |
{misses} |
s100.product |
Notes:
s100.productis the spec name (S-101,S-124,S-131, …).s100.asset.kindon the portrayal counter is one of:xslt,svg,line_style,area_fill,palette,lua_script,lua_source. (Same tag name is reused for asset-source I/O metrics with a disjoint value set — disambiguate by counter name.)- The Lua-source cache emits both the dedicated
s100.lua.source.cache.*counter and as100.portrayal.cache.*counter withs100.asset.kind=lua_sourceso dashboards that group on the generic portrayal counter still see the Lua source bucket. - The symbol / pattern counters previously had no tags. They now carry
s100.product, set by each dataset processor when it constructs the per-pipelineMapsuiDisplayListRenderer.
In a PerfReport summarise markdown report the rows look like:
| Metric | Sum |
| s100.symbol.cache.hit.count[s100.product=S-101] | 4123 |
| s100.symbol.cache.miss.count[s100.product=S-101] | 38 |
| s100.portrayal.cache.hit.count[s100.product=S-101][s100.asset.kind=svg] | 412 |
| s100.lua.source.cache.hit.count[s100.product=S-101] | 24 |
| s100.featurecatalogue.cache.hit.count[s100.product=S-101] | 19 |
Use PerfReport diff <baseline.jsonl> <candidate.jsonl> to see how
those numbers shift across runs. A healthy warm scenario shows
hit.count >> miss.count for the symbol and portrayal counters and a
non-zero featurecatalogue.cache.hit.count (every dataset open after
the first reuses the cached catalogue).
Wiring it up — the viewer
EncDotNet.S100.Viewer already wires OpenTelemetry into its DI
container via ViewerObservability.AddS100Observability. The
exporter honours the standard environment variables:
| Variable | Default |
|---|---|
OTEL_EXPORTER_OTLP_ENDPOINT |
http://localhost:4317 (gRPC) |
OTEL_EXPORTER_OTLP_PROTOCOL |
grpc |
OTEL_SERVICE_NAME |
EncDotNet.S100.Viewer |
OTEL_RESOURCE_ATTRIBUTES |
(none) |
When no collector is running the OTLP exporter retries silently — the viewer keeps working.
One-step: the Aspire AppHost (recommended)
src/EncDotNet.S100.AppHost is a .NET Aspire
host project that orchestrates the dashboard and the viewer in a
single command. It launches the Aspire dashboard, picks free OTLP
ports, and starts the viewer with OTEL_EXPORTER_OTLP_ENDPOINT /
OTEL_SERVICE_NAME / OTEL_RESOURCE_ATTRIBUTES already set:
dotnet run --project src/EncDotNet.S100.AppHost
The console prints a login URL like
http://localhost:15069/login?t=… — open it to see structured logs,
traces, and metrics from the running viewer side-by-side. Closing
either the AppHost console or the viewer window shuts both down.
No Docker required. The AppHost project does not participate in central package management — it is a self-contained orchestration shim.
Local Aspire dashboard (Docker, alternative)
If you don't want to run the AppHost, the dashboard can be run standalone:
docker run --rm -it -p 18888:18888 -p 4317:4317 \
mcr.microsoft.com/dotnet/aspire-dashboard:latest
OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4317 \
dotnet run --project src/EncDotNet.S100.Viewer
Open http://localhost:18888 to see structured logs, traces, and
metric scrapes side-by-side.
Local Jaeger (traces only)
docker run --rm -p 16686:16686 -p 4317:4317 \
jaegertracing/all-in-one:latest
OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4317 \
dotnet run --project src/EncDotNet.S100.Viewer
Jaeger UI: http://localhost:16686.
Wiring it up — your own host
Libraries are already instrumented; just subscribe to the right sources in your composition root:
using OpenTelemetry;
using OpenTelemetry.Trace;
using OpenTelemetry.Metrics;
using var tracer = Sdk.CreateTracerProviderBuilder()
.AddSource("EncDotNet.S100.*")
.AddOtlpExporter()
.Build();
using var meter = Sdk.CreateMeterProviderBuilder()
.AddMeter("EncDotNet.S100.*")
.AddOtlpExporter()
.Build();
Wildcard subscription requires OpenTelemetry SDK 1.10 or newer.
Testing
tests/EncDotNet.S100.Pipelines.Tests/TelemetrySmokeTests.cs
demonstrates how to assert on emitted activities using a plain
ActivityListener — no SDK required. Use the same pattern when
adding new instrumentation: register a listener, exercise the API,
assert on OperationName and tags.
Non-goals
- No log file sinks. Use the OTLP log exporter or wire any Microsoft.Extensions.Logging-compatible sink (Serilog, NLog, console) into your host.
- No allocation / GC profiling. GC collection-count deltas are
tagged on pipeline parent spans for rough comparison, but for
detailed allocation profiling use
dotnet-counters,dotnet-trace, orEventPipedirectly. - No custom dashboards. Aspire/Grafana/Tempo dashboards are out of scope; the metrics catalogue above is meant to be self-describing.
Reading a baseline run
The PerfRunner baseline
command captures a snapshot of all scenario timings at a specific git
commit. Baselines live in
tools/EncDotNet.S100.PerfRunner/baselines/<git-sha>/.
What's in a baseline directory
| File | Contents |
|---|---|
SUMMARY.md |
Git SHA, branch, commit subject, UTC timestamp, runtime info (OS, arch, CPU count, .NET version), and a per-scenario headline table (mean and P95 of the primary span). Also notes whether the run used synthetic-only data or the full corpus. |
<scenario>.jsonl |
Raw telemetry in the JSONL schema v1 — span records, histogram records, and counter records emitted during measured iterations. |
<scenario>.md |
Per-scenario markdown summary with min/P50/P90/P95/P99/max/mean iteration durations. |
The baselines/CURRENT file contains the SHA of the latest committed
baseline so tooling can locate it without parsing directory names.
Interpreting the data
Use the PerfReport tool:
# Summarise a single scenario's telemetry
dotnet run --project tools/EncDotNet.S100.PerfReport -- summarise \
tools/EncDotNet.S100.PerfRunner/baselines/<sha>/s101-portray-warm.jsonl
# Diff baseline vs. a fresh local run
dotnet run --project tools/EncDotNet.S100.PerfReport -- diff \
tools/EncDotNet.S100.PerfRunner/baselines/<sha>/s101-portray-warm.jsonl \
/tmp/perf/<sha>/s101-portray-warm.jsonl
The summarise command lists the top 20 spans by total duration plus
all histogram and counter metrics. The diff command compares
baseline and candidate side-by-side with status indicators:
| Symbol | Meaning |
|---|---|
| ❌ | ≥ 5% regression (higher duration / count) |
| ✅ | ≥ 10% improvement (lower duration / count) |
| ▫️ | < 5% change (stable) |
Caveats
Synthetic-only baselines exercise the same code paths as real-world datasets but with much smaller inputs. They exist for trend detection — catching regressions between commits — not for estimating production latency. The absolute numbers will be much lower than a real ENC or bathymetry grid.
A single laptop run is noisy; the CI perf gate (below) provides more authoritative comparisons on a consistent runner.
CI performance gating
The .github/workflows/perf.yml workflow runs on every PR to main
and catches regressions automatically:
- Builds the solution in Release mode.
- Runs PerfRunner
baselinewith--warmup 3 --iterations 10. - Runs PerfReport
gatecomparing the candidate run against the committed baseline (baselines/CURRENT). - Posts a markdown summary to the PR and fails the check when any
scenario's span or metric delta ≥ 10%. Spans and metrics with
baseline values below 50ms are excluded from gating (via
--min-abs) to avoid noise on tiny measurements.
The threshold is configurable via --threshold <PCT> on the gate
command. CI uses fewer iterations (10 vs 20) to reduce wall time.
Updating the baseline
After merging perf improvements, re-run the baseline and commit:
dotnet run --project tools/EncDotNet.S100.PerfRunner -- baseline
# Review baselines/<new-sha>/SUMMARY.md
echo "<new-sha>" > tools/EncDotNet.S100.PerfRunner/baselines/CURRENT
git add tools/EncDotNet.S100.PerfRunner/baselines/
git commit -m "perf: update baseline to <new-sha>"