Building a custom Notepad logger for ASP.NET Core

The Concept

When running and particularly when debugging programs, it is great to be able to see what the program is doing as it is doing it, or to go back afterwards and see what happened. For this, logs are invaluable.

There are many different kinds of logging systems. Logging to the console/terminal is typically the easiest, and part of what makes up a 12-factor app. Logging to file is easily the next common, but I had never considered logging to Notepad, until I came across this tweet:

Shoutout to /u/zid for the concept.

At first, this seems like a really horrible idea. We'd be taking all our log events, and blindly throwing them at a running Notepad process. This is very unusual and unorthodox.

But after thinking about it for a bit, it starts to make some sense. So, I thought, can I implement this as a logger provider for .NET Core / ASP.NET Core?

I've written a custom logger provider once before, for work, where we post our log events as JSON to a Kafka queue, and then they're taken from there and ingested into other systems. So I have a little bit of experience in this area already - it's not my first rode, but it is my second.

Building the logger

To build the logger, I started off by creating a new .NET Standard 2.0 class library project. This will enable my code to run on both .NET Core and .NET Framework applications. I gave it the name "Notepad.Extensions.Logging", which kind of mirrors the core framework name of Microsoft.Extensions.Logging", and also because I wouldn't be able to upload a package named "Microsoft.Extensions.Logging.Notepad" as the "Microsoft" prefix is reserved.

Registering a LoggerProvider

Since I'm building a custom logger, I first have to add a package dependency on Microsoft.Extensions.Logging so that I have access to all the basic types that I need.

Then, I need a way to register my new logger with the framework. The easiest way is to provide an extension method to ILoggingBuilder, so that users can easily add this logger in their project startup code.

To do this, I created an extension class like so:

using Notepad.Extensions.Logging;

namespace Microsoft.Extensions.Logging
{
    public static class LoggingBuilderExtensions
    {
        public static ILoggingBuilder AddNotepad(this ILoggingBuilder builder)
        {
            builder.AddProvider(NotepadLoggerProvider.Instance);
            return builder;
        }
    }
}

Since I don't have any customization options, I can always use the same NotepadLoggerProvider singleton. Of course, I actually have to define this class, so let's go ahead and build it:

using System.Text;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.ObjectPool;

namespace Notepad.Extensions.Logging
{
    class NotepadLoggerProvider : ILoggerProvider
    {
        NotepadLoggerProvider()
        {
            var poolProvider = new DefaultObjectPoolProvider();
            stringBuilderPool = poolProvider.CreateStringBuilderPool();
        }

        public static ILoggerProvider Instance { get; } = new NotepadLoggerProvider();

        readonly ObjectPool<StringBuilder> stringBuilderPool;

        public ILogger CreateLogger(string categoryName) => new NotepadLogger(stringBuilderPool, categoryName);

        public void Dispose() { }
    }
}

This defines a logger provider that does very little. It has a pool of StringBuilder objects, which will provide some optimizations later, and it can create a new ILogger implementation when it's asked for one. To use this pool though, I also needed to take a dependency on Microsoft.Extensions.ObjectPool.

Of course, one again, I have to actually define my ILogger implementation, so let's start building a NotepadLogger.

Building the core Logger functionality

ILogger has three methods we need to implement:

1. BeginScope, which takes some data and returns an IDisposable. Disposing of that object ends the scope. This isn't a logging feature I'm concerned with implementing, so I can just return a dummy object.
2. IsEnabled, which tells the caller if this logger is enabled or not. This can be useful for when the caller wants to calculate some expensive value to log, but can skip those calculations if the logger isn't going to log that particular message anyway. In my case, I'll accept any log message as long as we're running on Windows.
3. Log, which actually logs the message.

With that in mind, lets start setting up the logger. Here's the basic skeleton so far:

using System;
using System.Runtime.InteropServices;
using System.Text;
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.ObjectPool;

namespace Notepad.Extensions.Logging
{
    class NotepadLogger : ILogger
    {
        public NotepadLogger(ObjectPool<StringBuilder> stringBuilderPool, string categoryName)
        {
            this.stringBuilderPool = stringBuilderPool;
            this.categoryName = categoryName;
        }

        readonly ObjectPool<StringBuilder> stringBuilderPool;
        readonly string categoryName;

        public IDisposable BeginScope<TState>(TState state) => NullDisposable.Instance;

        public bool IsEnabled(LogLevel logLevel) => RuntimeInformation.IsOSPlatform(OSPlatform.Windows);

        public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
        {
        }
    }
}

In order for this to actually compile, I'll need to define my dummy NullDisposable object, which is fairly straightfoward:

using System;

namespace Notepad.Extensions.Logging
{
    class NullDisposable : IDisposable
    {
        public static IDisposable Instance { get; } = new NullDisposable();

        public void Dispose()
        {
        }
    }
}

Of course, since we haven't implemented ILogger.Log yet, this still doesn't do anything. To implement that, we need to do three things:

1. Exit, if our logger isn't enabled.
2. Otherwise, build our log message into some text.
3. Send that text to a running Notepad instance.

The first two are fairly easy, the third is where it gets tricky. Let's go ahead and implement the basics:

public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
{
    if (!IsEnabled(logLevel))
    {
        return;
    }

    if (formatter is null)
    {
        throw new ArgumentNullException(nameof(formatter));
    }

    var message = formatter(state, exception);

    if (string.IsNullOrEmpty(message) && exception is null)
    {
        return;
    }

    WriteMessage(logLevel, eventId.Id, message, exception);
}

Next, we need to put together a full textual representation of our log event. So far, all we've built is the message. We can do this by using that StringBuilder pool from earlier, and by combining the log level, category, event ID, and message:

void WriteMessage(LogLevel logLevel, int eventId, string message, Exception ex)
{
    var builder = stringBuilderPool.Get();
    try
    {
        builder
            .Append('[')
            .Append(GetLogLevelString(logLevel))
            .Append("] ")
            .Append(categoryName)
            .Append(" (")
            .Append(eventId)
            .Append(") ")
            .AppendLine(message);

        if (ex is { })
        {
            builder.Append("    ");
            builder.AppendLine(ex.ToString());
        }

        WriteToNotepad(builder.ToString());
    }
    finally
    {
        stringBuilderPool.Return(builder);
    }

    static string GetLogLevelString(LogLevel logLevel) => logLevel switch
    {
        LogLevel.Trace => "trce",
        LogLevel.Debug => "dbug",
        LogLevel.Information => "info",
        LogLevel.Warning => "warn",
        LogLevel.Error => "fail",
        LogLevel.Critical => "crit",
        _ => throw new ArgumentOutOfRangeException(nameof(logLevel)),
    };
}

The last bit we need to do is actually send this text to Notepad. To do this, we will need to call native Windows functions that do not have .NET equivalents readily available. For this, I defined a NativeMethods class (as is the naming convention for these):

static class NativeMethods
{
    [DllImport("User32.dll", CharSet = CharSet.Unicode, SetLastError = true)]
    public static extern IntPtr FindWindow(string lpClassName, string lpWindowName);

    [DllImport("User32.dll", CharSet = CharSet.Unicode, SetLastError = true)]
    public static extern IntPtr FindWindowEx(IntPtr hWndParent, IntPtr hWndChildAfter, string lpszClass, string lpszWindow);

    public const int EM_REPLACESEL = 0x00C2;

    [DllImport("User32.dll", CharSet = CharSet.Unicode, SetLastError = true)]
    public static extern IntPtr SendMessage(IntPtr hWnd, int Msg, IntPtr wParam, [MarshalAs(UnmanagedType.LPWStr)] string lParam);
}

Writing our logs to Notepad

The last thing we need to do now is implement WriteToNotepad to actually send our text to Notepad. This is where we finally get to insert the code from the original Reddit post:

static void WriteToNotepad(string message)
{
    IntPtr hwnd = NativeMethods.FindWindow(null, "Untitled - Notepad");
    if (hwnd == IntPtr.Zero)
    {
        hwnd = NativeMethods.FindWindow(null, "*Untitled - Notepad");
    }
    IntPtr edit = NativeMethods.FindWindowEx(hwnd, IntPtr.Zero, "EDIT", null);
    NativeMethods.SendMessage(edit, NativeMethods.EM_REPLACESEL, (IntPtr)1, message);
}

I've made a minor tweak here, which is to look for *Untitled - Notepad if a window named Untitled - Notepad could not be found. This is because once Notepad notices that it has changes, it adds the * to the titlebar to show that it is in a "dirty" state.

And, that's it! All we have to do now is add services.AddLogging(lb => lb.AddNotepad()); to our .NET application, and our logs will flow into any new Notepad document that it can find.

Conclusion

This was a surprisingly fun challenge that I managed to put together in a couple hours whilst also watching the Microsoft Build streams. If Microsoft Build had a Lightning Talks section, I definitely would have tried to put something together for that.

The logger structure is fairly straight-foward, though I've battled with a few concepts in the past (like scopes) that I just straight-up ignored this time around.

If you liked this, let me know! Also, on a future blog post, I'll talk about doing the same with Notepad++. 😈