Diagnostics and Instrumentation

Tracing

Fisher publishes an ActivitySource named Fisher, with spans around SaveChangesAsync, a LINQ execution and a document load.

builder.Services.AddOpenTelemetry().WithTracing(tracing =>
{
    tracing.AddSource("Fisher");
});

The instinct that tracing is for network calls is backwards here

An embedded store has no network calls, which sounds like it has nothing to trace. But SQLite serialises writers per file, so the interesting question about a slow Fisher call is almost always how long it waited for the write lock — and a request that spent its time queued behind another writer is otherwise indistinguishable from one that was simply slow.

The retry event is the point. It is recorded from the resilience pipeline against the enclosing span rather than as a span of its own, because a retry is the same operation happening again.

What is and is not covered

SaveChangesAsync	The whole commit, including a failed one — marked Error
A LINQ execution	Building and executing the statement
A document load	The read
A retry	An event on the enclosing span

TIP

A query's span covers building and executing the statement, not materializing the rows. Every terminal reads rows after the reader is returned, so covering materialization would mean a span per terminal — and the question the span exists to answer is entirely inside the boundary drawn.

The commit span's counts are tagged after everything that can add to the unit of work has run — listeners, inline projections — so they describe what was written rather than what had been asked for when the span opened.

TIP

Fisher instruments inside the session rather than through a decorator. Polecat's tracing decorator means re-implementing every member of IDocumentSession as a pass-through, a cost that grows with every feature added to the interface.

Two things learned writing the tests

WARNING

A contended write does not reach the retry the way you would expect. The wait at BEGIN IMMEDIATE comes from the connection string's Default Timeout and nowhere else — not SessionOptions.Timeout, which bounds a command, and not PRAGMA busy_timeout, which does not cover it. And Default Timeout=0 means no limit, not "do not wait".

So a contended save either sits for the full wait and succeeds with no retry, or fails while the connection is still being opened — since opening one applies the PRAGMAs, and journal_mode wants the write lock.

WARNING

An ActivityListener is process-wide, and test collections run in parallel. A test asserting Single(...) over recorded spans is green alone and red in a full suite. Filter by a tag the test's own store sets.

Metrics

Fisher publishes a Meter named Fisher, matching the ActivitySource, so one name subscribes to both:

builder.Services.AddOpenTelemetry().WithMetrics(metrics => metrics.AddMeter("Fisher"));

Everything is opt-in and nothing is created until it is asked for. A store that opts into nothing publishes no instruments and pays a null check on the commit path.

builder.Services.AddFisher(opts =>
{
    opts.ConnectionString = connectionString;

    opts.OpenTelemetry.TrackWriteLockContention();
    opts.OpenTelemetry.TrackEventCounters();
    opts.OpenTelemetry.TrackDocumentCounters();
});

Instrument	Kind	Tags	What it answers
fisher.write_lock.wait	histogram (ms)	fisher.store, fisher.write_lock.holder	How long a writer queued for SQLite's one write lock
fisher.write_lock.retries	counter	fisher.store, exception.type	How often a SQLITE_BUSY was retried rather than waited out
fisher.events.appended	counter	fisher.store, fisher.event.type, fisher.tenant	Append volume, by event type
fisher.documents.written	counter	fisher.store, fisher.document.type, fisher.document.operation	Commit shape — inserts, updates, deletions

fisher.write_lock.holder is session, daemon or rebuild. That distinction is what separates "the application is contended" from "the daemon is starving the application", which look identical from a session's side alone.

Why the wait, and not just the retries

WARNING

A SQLITE_BUSY retry counter on its own is the wrong instrument here, and that is a measurement rather than an opinion. Fisher's Polly pipeline already emits a fisher.retry activity event, so counting retries is the obvious move. Under the benchmark harness's concurrent-writers scenario that counter reads zero while throughput visibly collapses — a contended writer sits inside BEGIN IMMEDIATE under the connection string's busy timeout and eventually succeeds, never reaching the retry.

So a dashboard built on retries alone shows a flat line through the exact incident it exists to diagnose, which is worse than no instrument at all: a flat line reads as not the database. TrackWriteLockContention() therefore creates both — they are opted into together so neither can be charted without the other:

• a rising histogram with no retries is ordinary contention absorbed by the busy timeout;
• retries mean the timeout was exceeded, or the failure was SQLITE_BUSY_SNAPSHOT, which the busy timeout does not cover at all.

The counters are not Marten's

Marten's interesting number is connection usage against a pooled remote server. Fisher's is contention for the one write lock on a file, so the instruments differ:

Marten	Fisher
TrackConnections	refused — a Fisher connection is a file handle, not a lease on a scarce server resource. Weasel's SqliteDataSource builds a fresh connection per open, and the pooling beneath it is Microsoft.Data.Sqlite's, keyed process-wide by connection string and not attributable to a store. Setting it throws, naming TrackWriteLockContention() instead.
—	fisher.write_lock.wait — no sibling has one, because no sibling serialises every writer on a file
marten.event.append (TrackEventCounters)	fisher.events.appended, same shape. It earns its place here for an extra reason: on one file every appending writer is queued behind every other, so append volume charted against the wait separates more work arrived from the same work is now waiting
—	fisher.documents.written — the other cause of the wait
ExportCounterOnChangeSets<T>	same, for a counter specific to your own model

TIP

TrackConnections is refused rather than ignored, following SessionOptions.IsolationLevel, which is carried for parity and refuses exactly one value by name. A knob that silently does nothing is worse than an error, because the absence of data is indistinguishable from having none to report.

The event and document counters describe a user session's unit of work. An async projection commits through the daemon's batch, which deliberately does not fire session listeners — counting those here would put the daemon's own work on the same series as the application's.

The event store tooling surface

DocumentStore implements IEventStore explicitly, so none of a tooling-only surface lands on the store's own public API. Cast to reach it:

var eventStore = (IEventStore)store;

var streams = await eventStore.GetRecentStreamsAsync(…);
var metadata = await eventStore.GetStreamMetadataAsync(streamId);

WARNING

IEventStore, IEventStore<,> and ISubscriptionRunner<> are deliberately not on IDocumentStore. Re-exposing one through it would undo the point of implementing them explicitly.

The explorer reads have three scopes

GetRecentStreamsAsync, ReadStreamAsync and GetStreamMetadataAsync each come in three overloads, and on a database-per-tenant store the difference is not a convenience — it decides whether the answer is the whole store's.

// store-global
await eventStore.GetRecentStreamsAsync(10, ct);

// one tenant, wherever that tenant lives
await eventStore.GetRecentStreamsAsync(10, "north", ct);

// one database, from AllDatabases()
foreach (var database in await eventStore.AllDatabases())
{
    await eventStore.GetRecentStreamsAsync(database, 10, null, ct);
}

DatabaseCardinality is what tells the three apart, and on Fisher it is not always Single: one SQLite file is one database, but a database-per-tenant store is a file per tenant — StaticMultiple under MultiTenantedDatabases, DynamicMultiple under MultiTenantedDatabasesInDirectory and MultiTenantedDatabasesInRegistry.

What a store-global read does once there is more than one file depends on whether one answer can stand for all of them:

• The listing fans out and merges. "The ten most recently updated streams in this store" has an answer across a hundred files, and fi_streams.timestamp is fixed-width UTC text, so it compares across databases exactly as it does within one. Each merged summary is stamped with the tenant whose file it came from — which it has to be, because the tenant cannot be read off the row: under database-per-tenant the tenant_id column holds *DEFAULT* in every file.
• A single-stream lookup refuses. ReadStreamAsync and GetStreamMetadataAsync return one answer, and a stream id is unique within a database rather than across them — so there is no merge to perform, and answering from whichever file the store's default session resolved would be a confident wrong answer rather than a partial one. The refusal names both ways forward, and the listing above is where the tenant id comes from.

TIP

A tenant predicate in SQL is correct only under conjoined tenancy. Under database-per-tenant the tenant is the file, so naming a tenant resolves the database and adds no where clause. That is why an unknown tenant throws rather than falling back to the default file.

One read on that interface Fisher does not answer at any scope, and the database overload changes nothing for it: the dictionary-shaped QueryByTagsAsync. EventQuery.TagValues is the composable, paged home for that capability here, so there is no second code path to keep in step.

Projection statuses, and what State can honestly say

GetProjectionStatusesAsync carries the same three scopes, and answers the snapshot a monitoring console's projections page renders before it subscribes to ShardStatesChanged for live updates.

foreach (var projection in await eventStore.GetProjectionStatusesAsync(ct))
{
    foreach (var shard in projection.Shards)
    {
        Console.WriteLine($"{shard.ShardName}: {shard.State} " +
                          $"{shard.ProcessedSequence}/{shard.EventStoreSequence}");
    }
}

Four of ShardStatus's five fields come off the database. The fifth — State — is a fact about the running daemon, which fi_event_progression does not know, and that shapes the whole feature:

• A shard's state is Unknown when no daemon in this process can be asked, never Stopped. A store under DaemonMode.ExternallyManaged, a console in another process, and a hand-built store all genuinely cannot see the daemon. Stopped there is not a partial answer but a wrong one — it is exactly what a real stopped shard reports, and it is the reading an operator acts on.
• With a daemon this process hosts, the state is its tracker's. The vocabulary is closed at four values — Running, Paused, Stopped, Unknown — and a faulted shard reports Stopped with the latched exception's message in Error. A console renders this string and filters on it, so a fifth value would be a row that matches no filter rather than a more precise answer.
• EventStoreSequence is max(seq_id), not the persisted high-water row. The two agree on a store whose daemon is current, and differ exactly when it matters — the row is where the daemon got to, so reading it would make every shard on a stopped daemon look caught up.
• An inline or live projection is reported with an empty Shards list rather than omitted, and its Lifecycle is what says why the list is empty.
• The inventory is the registered projections, so a subscription is not in it. A subscription genuinely is a daemon shard with progress worth watching, but this is the page you open to ask about read models and a subscription has no document behind it. Its progress is reachable through IEventStore.RegisteredShardNames() correlated against IEventDatabase.FetchProjectionLagAsync — the pairing built for that question.

TIP

This surface is held to a shared definition across Marten, Polecat and Fisher by ProjectionStatusCompliance, and the Unknown-means-no-daemon reading above is the one it adopted.

WARNING

The store-global overload refuses on a database-per-tenant store, where the two single-stream reads above also refuse — but for a sharper reason. Progression rows are per database, and ShardStatus carries no database or tenant field, so N databases' rows would come back as N entries per shard with the same ShardName and different sequences, which a consumer cannot attribute. Name a tenant or a database.

TIP

A secondary store's marker proxy is not an IEventStore — DispatchProxy implements only the interfaces it was asked for. The IEventStore registration therefore reaches through the proxy to the real store, so a secondary store is still visible to a monitoring console.

Does this store have an event store at all?

IEventStore.HasEventStore is false for a document-only store: no registered event type other than Archived, and no projection or subscription. A console reads it before polling progression, dead letters and the head sequence, which a document-only store has nothing to report for. It is read on every call, never cached, because an event type registered on its first append turns a document-only store into an event store.

The document tooling surface

IDocumentStoreUsageSource, IDocumentStoreDiagnostics and projection step-through, also implemented explicitly.

var diagnostics = (IDocumentStoreDiagnostics)store;
var page = await diagnostics.QueryDocumentsAsync("Order", …);

Fisher implements the full IDocumentStoreDiagnostics contract from JasperFx 2.77.0 (jasperfx#870) and 2.78.0 (jasperfx#928), along with the write sibling IDocumentStoreDiagnosticsWriter. Both are registered in the container for the main store and for each ancillary store. What the contract defines:

• Every row carries metadata. DocumentQueryResult.Documents holds StoredDocuments with the version, LastModified, Created (when created_at is enabled), the tenant, the soft-delete flag and time, and the row's own .NET type. DocumentsJson is still filled for older consumers.
• Soft-deleted rows are excluded unless IncludeSoftDeleted is set. LoadDocumentAsync by id is an explicit request, so it returns a soft-deleted row with IsDeleted set rather than hiding it.
• A null, empty or whitespace tenant means the default tenant. It never means a tenant named "". Under database-per-tenant, the read goes to that tenant's own file. An unknown tenant throws rather than being answered from the default file.
• Every tenant is its own explicit request, AllTenants (JasperFx 2.78.0). Under conjoined tenancy it applies no tenant predicate; under database-per-tenant it reads every tenant's file, including several tenants sharing one. Each row carries its TenantId, and pages are ordered by tenant and then by id, so no page repeats a row from another. A single-tenanted type reads as the default tenant. Combining AllTenants with a named TenantId is an ArgumentException, and LoadDocumentAsync stays single-tenant.
• The version is opaque text. For a type with UseOptimisticConcurrency() it is the guid_version. For numeric revisions it is the revision number. For a type with neither, it is a hash of last_modified and the stored JSON. That token still changes on every write, so a console's guarded edit is guarded even for a type that did not opt into concurrency.
• Where and OrderBy are refused with DocumentCriteriaNotSupportedException. They are Dynamic LINQ text for the store's own IQueryable<T>, and that translation (jasperfx#869) has not shipped. Returning the unfiltered page would look like a filter that matched every row.

The writer saves or deletes through an ordinary session, so versions move, metadata is stamped and a soft-deleted type is soft-deleted. It checks ExpectedVersion inside Fisher's own write transaction, before it writes anything, so a stale edit comes back as ConcurrencyConflict with the current document. An unknown type, or JSON whose id disagrees with the requested id, is an ArgumentException.

Several things in that surface are worth knowing:

• The store is identified as fisher://{store name}, the same Subject the event side reports, not by its database file. Two stores sharing one file under different DatabaseSchemaNames are two identities. This changed in 1.14.0; before it, the document side reported the file's URI.
• The usage sweep forces the mappings into existence. A mapping is created lazily on first use, so a store that has opened no session has none — exactly the state a console sees on a fresh boot.
• PartitioningStrategy is reported as null rather than omitted. SQLite has no table partitioning, so the field has a value — none — rather than being unknown.
• A DDL failure is reported as a SQL comment, not thrown. One bad mapping should not take the whole store's description with it.
• QueryDocumentsAsync is hand-built SQL, and a fourth caller of the three implicit filters. It cannot go through Query<T>(): a console names its type as a string and filters on columns that are not document members. Each filter is composed from the one place that owns it rather than re-spelled.
• A table that does not exist reports an empty page, because SQLite resolves a table name at prepare time and a count against a never-created table fails before any guard could run.
• A sub-class name resolves to its base's mapping plus a doc_type filter, since a registered sub-class has no mapping of its own.
• A console's id is converted through the mapping's identity type before it is bound, because fi_doc_*.id holds the lowercase canonical Guid form under a case-sensitive collation.

The Event Model, derived from the store

AddFisher registers a ProjectionEventModelSource, so every registered projection appears on an Event Model canvas as a View slice — event → projection → read model — with nothing written down by hand.

Role	Read from
Slice name	the document type's name
Pattern	View
Projection	the projection's implementation type
Read model	the document type
Consumed events	the event types the projection's Apply / Create / Evolve methods take

Nothing has to be configured. AddFisherStore<T> registers a source of its own, so an ancillary store's projections reach the same model under a Subject that says which store they came from.

TIP

The slice is named after the document, not the projection, and that is what makes it merge with a spec-declared slice of the same name into one slice carrying both a Derived and a Declared claim — rather than two stickies that say the same thing. A bare subscription gets no slice: it has no read model behind it, so a sticky for one is something a reader cannot click through to.

Naming the model

The default follows the running service, JasperFxOptions.ServiceName — so a Wolverine application and its Fisher store land on one canvas with nothing configured at all.

WARNING

That needs Wolverine 6.38.0 or later (wolverine#4448, reported here as fisher#284). Wolverine names its own model from WolverineOptions.ServiceName, and until that release nothing carried the value back: ReadJasperFxOptions only ever did ServiceName ??= jasperfx.ServiceName, reading from JasperFx. So opts.ServiceName = "Ledgers" left the property this default reads at its own default, the entry assembly name, and the canvas split in two — the host's chains on one, this store's read models on the other.

It looked correct wherever the two coincide, a host whose assembly is named what its service is named agreeing with itself by accident. On an older Wolverine, set EventModelName rather than relying on the two defaults lining up.

Set EventModelName when a store is genuinely its own bounded context, as each module's store is in a modular monolith, or to match a host that passes something other than its service name to AddEventModel:

// Slices are grouped by MODEL NAME before they are merged, so a host that names its own model
// has to name the store's source to match -- otherwise the store's View slices assemble a
// second model called "EventModel" beside the host's, and neither canvas carries both halves.
services.AddFisher(options =>
{
    options.ConnectionString = connectionString;
    options.Projections.Snapshot<Report>(SnapshotLifecycle.Inline);

    options.EventModelName = "Storefront";
});

// An ancillary store is configured separately: it can be registered with no AddFisher at all,
// so there is no primary registration for it to read the name off.
services.AddFisherStore<IReportingStore>(options =>
{
    options.ConnectionString = connectionString;
    options.Projections.Snapshot<Report>(SnapshotLifecycle.Inline);

    options.EventModelName = "Storefront";
});

// Either side of the store registrations -- the name is read when the model is assembled.
services.AddEventModel("Storefront", model => model.Slice(nameof(Report)));

^{snippet source | anchor}

Each store is configured separately — AddFisherStore<T> can be registered with no AddFisher at all, so there is no primary registration for it to read a name off.

WARNING

Set it to a name nothing else uses and you get two models, not one. Slices merge by model name, so the store's slices land on one canvas and the host's declarations on another, with neither carrying both halves — which surfaces as Expected exactly one assembled model, but got [Storefront, EventModel] rather than as anything pointing at the registration.

An empty or whitespace name is refused by the setter, because it is a legal model name that reproduces the same bug with a blank where the name should be.

TIP

The fallback chain is EventModelName → JasperFxOptions.ServiceName → EventModel. The literal is the last resort, for a host with no JasperFx options registered at all. A blank service name falls through to it rather than naming a model nothing.

TIP

The order does not matter. EventModelName is read when the Event Model is assembled, not when the store is registered, so AddEventModel(...) may be called either side of AddFisher.

Projection step-through

Replay a stream one event at a time and capture the aggregate at each step:

var timeline = await ((IDocumentStoreDiagnostics)store).ReplayProjectionAsync<Order>(streamId, token);

WARNING

Each step copies the aggregate, and this is the one thing Polecat's equivalent does not do. JasperFx's aggregation mutates the aggregate in place, so a timeline built from live references shows the final state at every step — the single thing a step-through exists not to do.

The copy goes through the store's own serializer, which also makes each captured state exactly what would have been persisted.

A step's exception is recorded on the step rather than thrown, or the first bad event would hide every step after it. An unknown event type is skipped, following the stream reads' policy rather than the daemon's — a console may be pointed at a store holding types this deployment does not know.

Event store statistics

var stats = await store.Advanced.FetchEventStoreStatisticsAsync();

TIP

EventSequenceNumber can exceed EventCount, because archiving, compacting or deleting events leaves the sequence where it was. The gap between the two numbers is the count of events that once existed and no longer do. See Event Storage.

Health checks

builder.Services.AddHealthChecks().AddFisherHighWaterHealthCheck();

See ASP.NET Core Integration — including why it exists, and why the extended progression heartbeat column cannot answer the question it answers.

Seeing the SQL

var sql = session.ToSql(session.Query<User>().Where(x => x.Internal));

Parameter names, not values, so the text is readable rather than executable. It is the cheapest way to check that an implicit filter is actually present.

ToSql answers about one statement you already have in hand. For what a session actually ran, use the logger below.

Logging

Fisher logs through ILogger where a host supplies one — the WAL warning at daemon startup, and every statement a session executes.

The session logger

AddFisher attaches a DefaultFisherLogger over the container's ILogger<IDocumentStore>, so turning Fisher's SQL on is a log-level change and nothing else:

{ "Logging": { "LogLevel": { "Fisher": "Debug" } } }

Every statement then arrives with its duration, and each SaveChangesAsync with what it committed:

Fisher executed in 0.42 ms, SQL: insert into fi_doc_user (id, data, ...) ...
  @p0: (String)
  @p1: (String)
Fisher committed 3 operations in 1.86 ms — 2 updates, 1 inserts, 0 deletions, 4 events across 1 streams

Covered: the write batch (one line per storage operation), a LINQ execution, and a document load — the same three boundaries the spans are drawn at. A failed statement is logged with its command, and a failed commit is logged again as a message, because "this statement was refused" and "the whole unit of work is gone" are different news.

Parameter values are not logged by default

WARNING

This is a deliberate divergence from Marten, which logs p.Value for every parameter at Debug. Fisher logs the parameter's name and the CLR type of the bound value instead — @p0: (String).

Three things stack up behind it:

• Fisher already answered this question once, the same way. ToSql renders parameter names and not values, so that the text is readable rather than executable. One store should not hold two opposite answers to "may Fisher write bound values somewhere a human will read them".
• What is bound here is the whole document. A Fisher upsert binds the serialized document body as a single parameter, and an event append binds the event body the same way. "Log the parameter values" means every field of every document and every event, verbatim, at Debug.
• Fisher is embedded, so the blast radius is different. Marten's logs are a server-side application's. Fisher runs in-process next to its database file, very often on a desktop, an edge box or a device, where the log is a file on the same disk and is exactly the artifact attached to a support ticket. Turning on Debug to find out why a query is slow should not be the same gesture as exporting the database.

TIP

The type is not a placeholder for the value — it is the diagnostic for Fisher's sharpest binding trap. A Guid bound without conversion is written as a 16-byte BLOB that can never match the TEXT the schema holds, and every read then silently returns nothing. A line reading (Guid) where (String) belongs says that at once; the value would not.

Opt in when you need them:

builder.Services.AddFisher(opts =>
{
    opts.ConnectionString = connectionString;
    opts.LogSqlParameterValues = true;
});

This governs the shipped logger only. IFisherSessionLogger hands a custom logger the live DbCommand, values and all — what it does with them is its own decision.

Per store, per session

// The whole store
options.Logger(new ConsoleFisherLogger());

// Just this one session
session.Logger = new ConsoleFisherLogger();

IFisherLogger is the store-level factory and IFisherSessionLogger the per-session recorder, mirroring Marten's IMartenLogger / IMartenSessionLogger so that a logger ports across with a rename. Two of Marten's members are deliberately absent:

Marten member	Why Fisher does not carry it
LogSuccess(NpgsqlBatch) and its two siblings	There is no batch to log. SqliteBatch exists, but Fisher executes one command per storage operation on purpose — 1000 upserts take 4–6 ms as separate commands and 82–192 ms concatenated. The overload could never fire.
IMartenLogger.SchemaChange(string sql)	Fisher already has that seam one layer down. All of Fisher's DDL goes through Weasel, and FisherDatabase implements IDatabaseWithMigrationLogger — so migration output can already be routed anywhere without this interface. Honouring it here would mean displacing the DefaultMigrationLogger every Weasel provider type-checks to decide whether a failed DDL statement rethrows with its original stack trace.

The unlogged path costs nothing

A store built by hand — DocumentStore.For(...), which is what every test and every non-DI embedded use does — holds NulloFisherLogger, whose Enabled is a constant false. Every call site checks that before constructing any argument, so nothing is built for a logger that will discard it.

TIP

That guard is why IFisherSessionLogger.Enabled exists at all, and it is fisher#165's lesson held in advance: a DaemonTrace.Record call site once built its interpolated-string argument ahead of the gate that would have rejected it, so a facility documented as free cost an allocation per call. RecordSavedChanges is the same shape here — it wants an IChangeSet that SaveChangesAsync would not otherwise build. Measured: 0 bytes with the guard, 72 bytes per command without it.

A store that has a logger still records nothing until the level is on — DefaultFisherLogger.Enabled is ILogger.IsEnabled(LogLevel.Debug), asked every time rather than cached, so a host can change its levels while running.