Writing Custom Messages

This section describes how to write a standalone message using PostSharp Logging. Instead of a standalone message, you will often want to write a pair of messages to mark the beginning and the end (successful or not) of an activity. For this scenario, see Working with Custom Activities.

Writing text messages

The simplest scenario is to write a constant string.

To write a custom text message to the log:

1. Add the following statements on the top of your C# file:

   using PostSharp.Patterns.Diagnostics;
   using static PostSharp.Patterns.Diagnostics.FormattedMessageBuilder;
   

2. Add and initialize a static read-only field of type LogSource and initialize it with the Get() method:

   private static readonly LogSource logSource = LogSource.Get();
   

3. Evaluate the property corresponding to the desired log level, e.g. Debug or Error.

4. Invoke the Write<T>(in T, in WriteMessageOptions) method. For the first method, construct the message object by invoking the Formatted method.

   logSource.Debug.Write( Formatted( "Hello, world." ) );
   

Example

using PostSharp.Patterns.Diagnostics;
using static PostSharp.Patterns.Diagnostics.FormattedMessageBuilder;

static class Hasher
{
    private static readonly LogSource logSource = LogSource.Get();

    public static async Task ReadAndHashAsync(string url)
    {
       if ( string.IsNullOrEmpty( url ) )
       {
          logSource.Warning.Write( Formatted( "Empty URL passed. Skipping this method." ));
          return;
       }

       // Details skipped.
    }
}

Writing text messages with parameters

Most of the time, you won't log constant strings, but you will want to include variable pieces of information. In this case, you can use one of the overloads of the Formatted method that accepts formatting parameters.

Note that the specification of the formatting string used by the Formatted method is not identical to the one used by string.Format. The formatting string used by the Formatted method is designed to support named parameters (for use with logging backends that support it, e.g. Serilog connected to Elastic Search) and for high-performance evaluation.

The formatting string has the following specifications:

• Named parameters must be surrounded by curly brackets, e.g. {MyParameter}.

• Values are matched to named parameters by position. This means that the order of named parameters in the formatting string must match the order of corresponding values passed to the Formatted method and that two named parameters with the same name are not matched to the same value.

• Anything inside a pair of curly brackets is considered as the parameter name and will be passed to the backend as is, without further parsing.

• Formatting specifiers are not supported but may be partially supported in the future. Do not use colons (:) in your parameter names, as they may be interpreted differently in future versions of PostSharp.

• Use the escaped form of curly brackets {{ and }} if you want to include curly brackets in the formatted string.

Example

using PostSharp.Patterns.Diagnostics;
using static PostSharp.Patterns.Diagnostics.FormattedMessageBuilder;

static class Hasher
{
    private static readonly LogSource logSource = LogSource.Get();

    public static byte[] ReadAndHash(string url)
    {
        var hashAlgorithm = HashAlgorithm.Create("SHA256");
        hashAlgorithm.Initialize();

        var webClient = new WebClient();
        var buffer = new byte[16 * 1024];

        logSource.Info.Write( Formatted( "Using a {BufferSize}-byte buffer.", buffer.Length ) );

        using (var stream = webClient.OpenRead(url))
        {
            int countRead;
            while ((countRead = stream.Read(buffer, 0, buffer.Length)) != 0)
            {
                logSource.Info.Write( Formatted( "Got {CountRead} bytes.", countRead) );
                hashAlgorithm.ComputeHash(buffer, 0, countRead);
            }
        }

        return hashAlgorithm.Hash;
    }
}

Writing semantic messages for easy statistical processing

One common scenario in production is to prioritize the resolution of warnings based on the number of occurrences. It often makes more sense to start working on a warning happening 10 times per second than on one happening once per day.

Unfortunately, with text-based messages like those produced by FormattedMessageBuilder, this is cumbersome to achieve. The reason is that there is no message property to bucketize on.

When statistical processing of messages is important to you, you should use, instead of formatted messages, semantic messages produced by the SemanticMessageBuilder class. Semantic messages have a name and a list of properties, but no text.

To emit semantic messages, use the Semantic method instead of Formatted.

Example

using PostSharp.Patterns.Diagnostics;
using static PostSharp.Patterns.Diagnostics.SemanticMessageBuilder;

static class Hasher
{
    private static readonly LogSource logSource = LogSource.Get();

    public static byte[] ReadAndHash(string url)
    {
        var hashAlgorithm = HashAlgorithm.Create("SHA256");
        hashAlgorithm.Initialize();

        var webClient = new WebClient();
        var buffer = new byte[16 * 1024];

        logSource.Info.Write( Semantic( "Initialize", ("BufferSize", buffer.Length ) ) );

        using (var stream = webClient.OpenRead(url))
        {
            int countRead;
            while ((countRead = stream.Read(buffer, 0, buffer.Length)) != 0)
            {
                logSource.Info.Write( Semantic( "ReadChunk", ("CountRead", countRead ) ) );
                hashAlgorithm.ComputeHash(buffer, 0, countRead);
            }
        }

        return hashAlgorithm.Hash;
    }
}

Using default log levels

In the previous sections, we have explicitly specified the message severity by using the Debug, Trace, Info, Warning, Error and Critical properties. Instead of using these properties, you can use the WithLevel(LogLevel) method, which takes a parameter of type LogLevel.

Alternatively, you can use the Default and Failure properties. They resolve to the default level for success or failure messages. The default levels are Debug for Default and Error for Failure. The default levels can be configured with the WithLevels(LogLevel, LogLevel) method. This method allows you to configure the default levels from a central place.

To configure the default logging levels centrally:

1. Define an internal static field of type LogSource for the prototype instance. Instantiate the prototype instance using Get() and configure it using WithLevels(LogLevel, LogLevel).

2. For each type, clone the prototype using the ForType(Type) or ForCurrentType() method.

Example

The following example illustrates how to configure log sources centrally:

using PostSharp.Patterns.Diagnostics;
using static PostSharp.Patterns.Diagnostics.FormattedMessageBuilder;

static class LogSources
{
   // Configure a prototype LogSource that you will reuse in several classes.
   public static readonly LogSource Default = LogSource.Get().WithLevels( LogLevel.Trace, LogLevel.Warning );
}

class MyClass
{
   // Instantiates a LogSource from the prototype for the current type.
   static readonly LogSource logSource = LogSources.Default.ForCurrentType();

   void MyMethod()
   {
      // Write a message with default verbosity.
      logSource.Default.Write( Formatted( "Hello, World." ) );
   }
}

Optimizing performance with the 'Elvis' operator

When you are writing a message, the first thing that the Write<T>(in T, in WriteMessageOptions) method does is to check whether the requested logging level is enabled. If not, nothing else happens. If yes, the message is rendered and emitted. Altought this may seem fast enough for many scenarios, sometimes the cost of evaluating the parameters passed to Formatted and Semantic is prohibitive in itself. For these situations, it is preferable to skip the invocation of Formatted, Semantic and Write<T>(in T, in WriteMessageOptions) altogether if the current verbosity is insufficient.

One way to conditionally emit a message is to use an if and test for the IsEnabled property.

However, it is much more convenient to use the EnabledOrNull and the C# "Elvis" operator, e.g. as in the construct logSource.Debug.EnabledOrNull?.Write.

Example

The following example uses the EnabledOrNull and the Elvis operator to make sure the expensive File.GetLastWriteTime method is evaluated only when debug-level logging is enabled.

logSource.Debug.EnabledOrNull?.Write( Formatted( "The last change date of the file is {LastChangeDate}.", File.GetLastWriteTime("oh-my.txt")  ) );

Implementing your own type of messages

If neither FormattedMessageBuilder nor SemanticMessageBuilder fit your needs, you can create your own type of messages.

Messages are types (preferably value types) that implement the IMessage interface. It has a single method, Write(ICustomLogRecordBuilder, CustomLogRecordItem), which should render the message into an ICustomLogRecordBuilder.

You can use the FormattingStringParser type if you want to reuse the same formatting string syntax as the one used by FormattedMessageBuilder.

See Also

Other Resources

Adding Properties to Messages and Activities