Log.Assert 0.2.0-pre1

Log.Assert( it is "A better style of application logging" )

Log.Assert and Serilog.Assert add assertion-style application logging to ILogger.

public string GoBang(string target, int guess)
{
    log.Me();
    log.PreconditionNotNull(target);

    var graphemes = new StringInfo(target??"");
    log.Assert(graphemes.LengthInTextElements > 0);
    log.Precondition(0 <= guess && guess <= graphemes.LengthInTextElements);

    log.ExceptionAndThrowIf(
        graphemes.SubstringByTextElements(guess,1) is "💥",
        new ApplicationException("bang!"));

    var remainder = Remove(graphemes,guess);
   
    log.DebugIf(remainder.Length == 0,"TBC:is this permitted?");
    log.If(graphemes.LengthInTextElements > 0,
              helpfulInformation: (target,guess,graphemes.LengthInTextElements),
              label: "Remaining after Removal");

    log.PreconditionNotNull(target);
    log.Postcondition(remainder.Length < target.Length);
    log.Me(remainder);
    return remainder;
}

What is Logged?

• All methods log the current method or member name.
• Assertions, Pre-, and Post-Conditions log nothing at all if they pass.
• Assertions, Pre-, and Post-Conditions log the literal failed expression if they fail.
• log.If() methods log nothing at all if the condition is false
• log.If() methods log the literal condition expression if it is true
• All methods can log additional information, either auto-labelled or explicitly labelled.

Do log.Assertions throw?

No, they log. Traditionally, assertions are stripped out for release, and take effect only when code is compiled in debug mode. Log.Assert strongly encourages you to instead keep the assertions and log the failures. (But there are also log.AssertElseThrow() methods, which do throw on failure).

Do I have to use pre- and post-conditions everywhere now?

No, you don't. Try a few and see what you learn.

Example output

Depending on your logger template configuration, something like:

INF] GoBang((target,guess)=(12🍾4💥, 1))
ERR] GoBang:Precondition Not Null Failed:target:
ERR] GoBang:Assertion Failed:graphemes.LengthInTextElements > 0:
ERR] GoBang:Precondition Failed:0 <= guess && guess <= graphemes.LengthInTextElements
INF] GoBang:graphemes.LengthInTextElements > 0:Remaining after Removal:(12🍾4💥, 1, 5)
ERR] GoBang:Postcondition Failed:0 <= guess && guess <= graphemes.LengthInTextElements
INF] GoBang(remainder=1🍾4💥)

Structured Logging Properties

The default properties sent to structured logging are:

• All methods log the current method or member name as a string {Action}
• Assertions, Pre-, and Post-Conditions log their {Assertion} as a literal code string
• log.If() and log.IfNot() methods log their {Condition} as a literal code string
• All methods log optional helpfulInformation as an object {@State} and a string {Label}
• Exceptions log {Exception} just as the frameworks normally do.

{@State} is the only complex property, everything else is a string.

{Action} and {Label} values can be overridden inline:

log.Me(state, action:"Not the method name", label:"Not the auto-generated label")

Changing the Template Strings and Structured Property Names

To change the message templates, and the property names used for structured logging, set the properties of TemplateStrings static class to the template strings and property names you want.

For instance if you set

TemplateStrings.Me = "{MethodName}({Title}{Info})";

Then log.Me(param1) will result in structured logging properties:

{MethodName} = "<Method or member name>"
{Title} = "param1"
{Info} = <value of param1>

instead of the default {Action},{Label},{State}.

The default template strings are stored as constants in TemplateStrings.Defaults.

Log Level

• Assertions, Pre-, and Post-Conditions log at level Error.
• Other methods default to logging at level Information, with named methods for other log levels (see the full list below).
• Exceptions log at level Error by default.

All Methods

All methods accept an optional additonal helpfulInformation parameter, and an optional label for it.

log.Me()
log.MeDebug()
log.MeTrace()   //Log.Assert
log.MeVerbose() //Serilog.Assert
log.MeWarning()
log.MeError()

log.Assert()
log.AssertNotNull()
log.AssertNotNullOrEmpty()
log.AssertNotNullOrWhitespace()

log.Precondition()
log.PreconditionNotNull()
log.PreconditionNotNullOrEmpty()
log.PreconditionNotNullOrWhitespace()

log.Postcondition()
log.PostconditionNotNull()
log.PostconditionNotNullOrEmpty()
log.PostconditionNotNullOrWhitespace()

log.AssertElseThrow()
log.AssertNotNullElseThrow()

log.PreconditionElseThrow()
log.PreconditionNotNullElseThrow()

log.PostconditionElseThrow()
log.PostconditionNotNullElseThrow()

log.If()
log.InformationIf()
log.DebugIf()
log.TraceIf()   //Log.Assert
log.VerboseIf() //Serilog.Assert
log.WarnIf()
log.ErrorIf()
log.CriticalIf() //Log.Assert
log.FatalIf()    //Serilog.Assert

log.IfNot()
log.InformationIfNot()
log.DebugIfNot()
log.TraceIfNot()    //Log.Assert
log.VerboseIfNot()  //Serilog.Assert
log.WarnIfNot()
log.ErrorIfNot()
log.CriticalIfNot() //Log.Assert
log.FatalIfNot()    //Serilog.Assert

log.Exception()
log.ExceptionIf()
log.ExceptionAndThrow()
log.ExceptionAndThrowIf()
log.CriticalThenThrow()                       //Log.Assert
log.CriticalExceptionThenExitProcessWithCode() //Log.Assert
log.FatalThenThrow()                          //Serilog.Assert
log.FatalExceptionThenExitProcessWithCode()   //Serilog.Assert

Logging additional helpfulInformation

//Use a ValueTuple or anonymous object to log multiple items of additional state 
log.Me( (this,that,other) );

// By default the log line will auto-label the state:
"MethodName:(this,that,other)=(value1,value2,value3)"

// You can explicitly label the state:
log.Me( (this,that,other), "Checkpoints 1 to 3")
"MethodName:Checkpoints 1 to 3=(value1,value2,value3)"

// additional state can be just a comment:
log.Me("Comment ...")
"MethodName:Comment ..."

What about performance?

For applications where the billionths of a second it takes to compute an assertion success are more critical than visibility of assertion failures, then you will not want to use logging assertions, you can use traditional assertions instead. Programs running on shared virtual infrastructure or making a network call do not fall into this category.

Billionth of a second?

I reckon a typical boolean assertion in a hotspot in a running program won't go beyond your processor's L2 cache, so we're talking clock cycles — nanoseconds, not milliseconds.

Reference and Inspiration

Logging production assertion failures can be an eye-opener. Jim Coplien made this point some years ago in his paper, Most Unit Testing is Waste. Why would you test only in a unit test run? Test in production too, it's what the pros do. (I offer no opinion on whether his title is statistically true. Obviously none of my unit tests are waste, because I deleted the pointless ones).

Proofs of program correctness have not been as fashionable as automated testing for the past thirty years. Now is your chance to join the trendsetters before everyone is doing it.