Diagnostics and Instrumentation Edit on GitHub

So far, Marten has diagnostics, command logging, and unit of work life cycle tracking.

For information on accessing and previewing the database schema objects generated by Marten, see Marten and the Postgresql Schema

Listening for Document Store Events

All of the functionality in this section was added as part of Marten v0.8

Marten has a facility for listening and even intercepting document persistence events with the IDocumentSessionListener interface:


public interface IDocumentSessionListener
{
    void BeforeSaveChanges(IDocumentSession session);

    Task BeforeSaveChangesAsync(IDocumentSession session, CancellationToken token);

    void AfterCommit(IDocumentSession session, IChangeSet commit);

    Task AfterCommitAsync(IDocumentSession session, IChangeSet commit, CancellationToken token);

    void DocumentLoaded(object id, object document);

    void DocumentAddedForStorage(object id, object document);
}

You can build and inject your own listeners by adding them to the StoreOptions object you use to configure a DocumentStore:


var stub1 = new StubDocumentSessionListener();
var stub2 = new StubDocumentSessionListener();

using (var store = SeparateStore(_ =>
{
    _.Connection(ConnectionSource.ConnectionString);
    _.AutoCreateSchemaObjects = AutoCreate.All;
}))

The listeners can be used to modify an IDocumentSession and its related unit of work just before persisting. Marten itself will be using this mechanism internally to perform projections in the future.

The following fake, sample listener demonstrates how you can query into the pending changes before making a transactional commit, and also how to query what was done after a commit is made:


// DocumentSessionListenerBase is a helper abstract class in Marten
// with empty implementations of each method you may find helpful
public class SimpleSessionListener: DocumentSessionListenerBase
{
    public override void BeforeSaveChanges(IDocumentSession session)
    {
        // Use pending changes to preview what is about to be
        // persisted
        var pending = session.PendingChanges;

        // Careful here, Marten can only sort documents into "inserts" or "updates" based
        // on whether or not Marten had to assign a new Id to that document upon DocumentStore()
        pending.InsertsFor<User>()
            .Each(user => Debug.WriteLine($"New user: {user.UserName}"));

        pending.UpdatesFor<User>()
            .Each(user => Debug.WriteLine($"Updated user {user.UserName}"));

        pending.DeletionsFor<User>()
            .Each(d => Debug.WriteLine(d));

        // This is a convenience method to find all the pending events
        // organized into streams that will be appended to the event store
        pending.Streams()
            .Each(s => Debug.WriteLine(s));
    }

    public override void AfterCommit(IDocumentSession session, IChangeSet commit)
    {
        // See what was just persisted, and possibly carry out post
        // commit actions

        var last = commit;

        last.Updated.Each(x => Debug.WriteLine($"{x} was updated"));
        last.Deleted.Each(x => Debug.WriteLine($"{x} was deleted"));
        last.Inserted.Each(x => Debug.WriteLine($"{x} was inserted"));
    }
}

As of Marten 1.4, you can also register IDocumentSessionListener objects scoped to a particular session with the DocumentStore.OpenSession(SessionOptions) signature.

Custom Logging

Marten v0.8 comes with a new mechanism to plug in custom logging to the IDocumentStore, IQuerySession, and IDocumentSession activity:


public interface IMartenLogger
{
    IMartenSessionLogger StartSession(IQuerySession session);

    void SchemaChange(string sql);
}

public interface IMartenSessionLogger
{
    void LogSuccess(NpgsqlCommand command);

    void LogFailure(NpgsqlCommand command, Exception ex);

    void RecordSavedChanges(IDocumentSession session, IChangeSet commit);
}

To apply these logging abstractions, you can either plug your own IMartenLogger into the StoreOptions object and allow that default logger to create the individual session loggers:


var store = DocumentStore.For(_ =>
{
    _.Logger(new ConsoleMartenLogger());
});

You can also directly apply a session logger to any IQuerySession or IDocumentSession like this:


using (var session = store.OpenSession())
{
    // Replace the logger for only this one session
    session.Logger = new RecordingLogger();
}

The session logging is a different abstraction specifically so that you could track database commands issued per session. In effect, my own shop is going to use this capability to understand what HTTP endpoints or service bus message handlers are being unnecessarily chatty in their database interactions. We also hope that the contextual logging of commands per document session makes it easier to understand how our systems behave.


public class ConsoleMartenLogger: IMartenLogger, IMartenSessionLogger
{
    public IMartenSessionLogger StartSession(IQuerySession session)
    {
        return this;
    }

    public void SchemaChange(string sql)
    {
        Console.WriteLine("Executing DDL change:");
        Console.WriteLine(sql);
        Console.WriteLine();
    }

    public void LogSuccess(NpgsqlCommand command)
    {
        Console.WriteLine(command.CommandText);
        foreach (var p in command.Parameters.OfType<NpgsqlParameter>())
        {
            Console.WriteLine($"  {p.ParameterName}: {p.Value}");
        }
    }

    public void LogFailure(NpgsqlCommand command, Exception ex)
    {
        Console.WriteLine("Postgresql command failed!");
        Console.WriteLine(command.CommandText);
        foreach (var p in command.Parameters.OfType<NpgsqlParameter>())
        {
            Console.WriteLine($"  {p.ParameterName}: {p.Value}");
        }
        Console.WriteLine(ex);
    }

    public void RecordSavedChanges(IDocumentSession session, IChangeSet commit)
    {
        var lastCommit = commit;
        Console.WriteLine(
            $"Persisted {lastCommit.Updated.Count()} updates, {lastCommit.Inserted.Count()} inserts, and {lastCommit.Deleted.Count()} deletions");
    }
}

Accessing Diagnostics

All the diagnostics are going to be exposed off of the IDocumentStore.Diagnostics property. Today, the only capabilities are to get a preview of the generated storage code or a preview of the ADO.NET code that will be generated for a LINQ query.

Previewing LINQ Queries

Let's say that we have a small document type called Trade:


public class Trade
{
    public int Id { get; set; }

    [DuplicateField]
    public double Value { get; set; }
}

The [DuplicateField] attribute directs Marten to duplicate the value of Value into a separate database field for more efficient querying. Now, let's say that we want to search for every Trade document with a value of over 2,000, but we want to see the SQL query that Marten will build for that query first:


// store is the active IDocumentStore
var queryable = theStore.QuerySession().Query<Trade>().Where(x => x.Value > 2000);
var cmd = queryable.ToCommand(FetchType.FetchMany);

Debug.WriteLine(cmd.CommandText);

The sql string in our debug window for the code above is:

select d.data from mt_doc_trade as d where d.value > :arg0

Previewing the PostgreSQL Query Plan

Marten has a helper to find and preview the PostgreSQL EXPLAIN plan for a Linq query. Our hope is that this will be a valuable aid to teams who need face performance problems while using Marten. The syntax for fetching the EXPLAIN plan for the Linq query from the previous section is shown below:


// Explain() is an extension method off of IQueryable<T>
var plan = queryable.Explain();
Console.WriteLine($"NodeType: {plan.NodeType}");
Console.WriteLine($"RelationName: {plan.RelationName}");
Console.WriteLine($"Alias: {plan.Alias}");
Console.WriteLine($"StartupCost: {plan.StartupCost}");
Console.WriteLine($"TotalCost: {plan.TotalCost}");
Console.WriteLine($"PlanRows: {plan.PlanRows}");
Console.WriteLine($"PlanWidth: {plan.PlanWidth}");

The console output for the code below (on my box) was:

NodeType: Seq Scan
RelationName: mt_doc_trade
Alias: d
StartupCost: 0
TotalCost: 24.13
PlanRows: 377
PlanWidth: 36

Request Counting and Thresholds

Marten has several facilities for improving system performance by reducing the number of network round trips to the server, but the first step maybe to just understand what kinds of operations are being chatty in the first place. To that end, Marten exposes the request count for each IQuerySession or IDocumentSession that simply tells you how many commands have been issued to Postgresql by that session:


using (var session = theStore.QuerySession())
{
    var users = session.Query<User>().ToList();
    var count = session.Query<User>().Count();
    var any = session.Query<User>().Any();

    session.RequestCount.ShouldBe(3);
}

At this point, Marten does not have any built in support for asserting requests per session thresholds like other tools. While I think that we are uncomfortable with that functionality ever being turned on in production, it should be easily feasible to build those kinds of automated threshold testing like "fail the test if there were more than 25 requests issued for any given HTTP request."

Getting PostgreSQL server version

Marten provides a helper method to fetch the PostgreSQL server version exposed via IDocumentStore.Diagnostics. This is helpful to enable feature toggles based on features available in PostgreSQL versions or perform any diagnostics.


var pgVersion = theStore.Diagnostics.GetPostgresVersion();

Next

Previous