logging.md

Logging

By default some information is written to Trace.WriteLine

• The SqlLocalDb instance name when SqlInstance is instantiated.
• The database name when a SqlDatabase is built.

To enable verbose logging use LocalDbLogging:

LocalDbLogging.EnableVerbose();

^{snippet source | anchor}

The full implementation is:

/// <summary>
///     Controls the logging level.
/// </summary>
public static class LocalDbLogging
{
    /// <summary>
    ///     Enable verbose logging to <see cref="Trace.WriteLine(string)" />
    /// </summary>
    public static void EnableVerbose(bool sqlLogging = false)
    {
        if (WrapperCreated)
        {
            throw new("Must be called prior to `SqlInstance` being created.");
        }

        Enabled = true;
        SqlLoggingEnabled = sqlLogging;
    }

    internal static bool SqlLoggingEnabled;
    internal static bool Enabled;
    internal static bool WrapperCreated;

    internal static void LogIfVerbose(string message)
    {
        if (Enabled)
        {
            Log(message);
        }
    }

    internal static void Log(string message)
    {
        try
        {
            Console.WriteLine($"LocalDb: {message}");
        }
        // dont care if log fails
        catch
        {
        }
    }
}

^{snippet source | anchor}

Which is then combined with Fody MethodTimer:

static class MethodTimeLogger
{
    public static void Log(MethodBase method, long milliseconds, string? message)
    {
        if (!LocalDbLogging.Enabled)
        {
            return;
        }

        if (message is null)
        {
            LocalDbLogging.Log($"{method.Name} {milliseconds}ms");
            return;
        }

        LocalDbLogging.Log($"{method.Name} {milliseconds}ms {message}");
    }
}

^{snippet source | anchor}

SQL statements

SQL statements can be logged:

LocalDbLogging.EnableVerbose(sqlLogging: true);

^{snippet source | anchor}

And an example database creation message would be:

LocalDB: Executed SQL (87.ms):
    if db_id('Tests_SeedData') is null
        begin
            create database [Tests_SeedData] on
            (
                name = [Tests_SeedData],
                filename = 'D:\LocalDBData\TestDbContext\Tests_SeedData.mdf'
            ),
            (
                filename = 'D:\LocalDBData\TestDbContext\Tests_SeedData_log.ldf'
            )
            for attach;
        end;
    else
        begin
            alter database [Tests_SeedData] set online;
        end;

In EfLocalDb this will also log EntityFramework SQL statements.

So performing a DbSet.FindAsync() would result in:

LocalDB: Executed EF SQL command:
    Executed DbCommand (73ms) [Parameters=[@p0='prop' (Size = 4000)], CommandType='Text', CommandTimeout='30']
    SET NOCOUNT ON;
    INSERT INTO [TestEntities] ([Property])
    VALUES (@p0);
    SELECT [Id]
    FROM [TestEntities]
    WHERE @@ROWCOUNT = 1 AND [Id] = scope_identity();

Logging in xUnit

xUnit does not route Trace.WriteLine to ITestOutputHelper. Tracking issue: 3.0: Console / Trace / Debugger capture support .

This can be worked around by adding a Trace Listener that writes to ITestOutputHelper.

Or alternatively use XunitLogger: https://github.com/SimonCropp/XunitLogger.