serilog-expressions icon indicating copy to clipboard operation
serilog-expressions copied to clipboard

Removed allocations for timestamp

Open epeshk opened this issue 1 year ago • 2 comments

Similar to https://github.com/serilog/serilog/pull/2094

Removed allocations from DateTimeOffset.ToString by using ISpanFormattable.TryFormat API

[MemoryDiagnoser]
[SimpleJob(RuntimeMoniker.Net80)]
[SimpleJob(RuntimeMoniker.Net90)]
public class ExpressionBenchmark
{
  private TextWriter nullWriter = TextWriter.Null;
  private ExpressionTemplate expressionFormatter = new ExpressionTemplate("[{@t:HH:mm:ss.fff} {@l:u3} ({SourceContext})] {@m}\n");
  
  private readonly LogEvent logEvent = new LogEvent(DateTimeOffset.Now, LogEventLevel.Information, null, new MessageTemplateParser().Parse("Something happens in method {Method} with parameter {Param}, context: {Context}"), new LogEventProperty[
  ]
  {
    new LogEventProperty("Method", new ScalarValue("ProcessMessages")),
    new LogEventProperty("Param", new ScalarValue(12345678)),
    new LogEventProperty("Context", new ScalarValue("DummyContext"))
  });

  [Benchmark]
  public void WriteEvent() => expressionFormatter.Format(logEvent, nullWriter);
}

Before

Method Job Runtime Mean Error StdDev Gen0 Allocated
WriteEvent .NET 8.0 .NET 8.0 222.9 ns 1.11 ns 0.86 ns 0.0210 176 B
WriteEvent .NET 9.0 .NET 9.0 180.3 ns 1.52 ns 1.42 ns 0.0210 176 B

After

Method Job Runtime Mean Error StdDev Gen0 Allocated
WriteEvent .NET 8.0 .NET 8.0 225.5 ns 1.52 ns 1.34 ns 0.0086 72 B
WriteEvent .NET 9.0 .NET 9.0 163.0 ns 1.73 ns 1.54 ns 0.0086 72 B

epeshk avatar Jul 25 '24 11:07 epeshk

Hi @epeshk, thanks for sending this, looks like a fantastic improvement :+1:

DateTime(Offset) format strings don't have any natural maximum length in .NET, so the following kind of thing is valid:

Console.WriteLine("{0:----------------------------------------------}", DateTimeOffset.Now);

I think it's fine to apply a limitation like "format strings can't result in more than 36 chars" but perhaps this could be documented using a constant and a unit test, so that we can be sure if a format string ends up producing output longer than what we'd expect, the results are reasonable?

Definitely in favor of this change otherwise 👍

nblumhardt avatar Aug 02 '24 23:08 nblumhardt

Reading the code again, I see that we should fall through and still create correct output in the "too long" case - think it just needs a test :-)

nblumhardt avatar Aug 02 '24 23:08 nblumhardt