serilog / serilog-expressions

An embeddable mini-language for filtering, enriching, and formatting Serilog events, ideal for use with JSON or XML configuration.
Apache License 2.0
193 stars 17 forks source link

String arguments are not colorized when using a custom ExpressionTemplate #56

Closed oising closed 2 years ago

oising commented 3 years ago

I noticed that when using a custom ExpressionTemplate, my placeholders in log messages are no longer colorized. Is this a bug? e.g. Log.Information("foo {bar}", "bar") won't color the "bar" anymore.

I suspect it's only a problem with string arguments.

My template:

var template = new ExpressionTemplate(
                "[{@l:u3}] {Coalesce(Substring(SourceContext, LastIndexOf(SourceContext, '.') + 1),'Core')} " +
                "<{ThreadId}> {@m}\n{@x}", theme: TemplateTheme.Code);

Without ExpressionTemplate:

image

With ExpressionTemplate:

image

I'm not sure if this a problem in expressions, or in the console sink.

oising commented 3 years ago

I'm using the latest console and expression nuget libs (4.0 and 3.2.1 respectively)

nblumhardt commented 3 years ago

Which terminal are you using? I can't repro with:

using Serilog;
using Serilog.Templates;
using Serilog.Templates.Themes;

Log.Logger = new LoggerConfiguration()
  .WriteTo.Console(
      new ExpressionTemplate("{@m}\n", theme: TemplateTheme.Code)
  )
  .CreateLogger();

Log.Information("Hello {Name}!", "world");

and

<Project Sdk="Microsoft.NET.Sdk">

  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFramework>net6.0</TargetFramework>
    <ImplicitUsings>enable</ImplicitUsings>
    <Nullable>enable</Nullable>
  </PropertyGroup>

  <ItemGroup>
    <PackageReference Include="serilog.expressions" Version="3.2.1" />
    <PackageReference Include="serilog.sinks.console" Version="4.0.0" />
  </ItemGroup>

</Project>
oising commented 3 years ago

The screenshots are from the JetBrains Rider IDE's integrated terminal.

nblumhardt commented 3 years ago

Does it repro in other terminals? Thanks!

nblumhardt commented 3 years ago

Or in Rider, choosing another theme (e.g. TemplateTheme.Literate?)

GerkinDev commented 2 years ago

This issue is still present AFAICT.

Using ExpressionTemplate

TemplateTheme.cs

namespace MyApp
{
    public static class TemplateTheme
    {
        /// <summary>
        /// A 256-color theme along the lines of Visual Studio Code.
        /// </summary>
        public static TemplateTheme Literate { get; } = new(
            new Dictionary<TemplateThemeStyle, string>
            {
                // Customized values from `Serilog.Sinks.Console` `Literate` theme, plus some custom ones
                [TemplateThemeStyle.Text] = "\u001b[38;5;0015m",
                [TemplateThemeStyle.SecondaryText] = "\u001b[38;5;0007m",
                [TemplateThemeStyle.TertiaryText] = "\u001b[38;5;0008m",
                [TemplateThemeStyle.Invalid] = "\u001b[38;5;0011m",
                [TemplateThemeStyle.Null] = "\u001b[38;5;0027m",
                [TemplateThemeStyle.Name] = "\u001b[38;5;0007m",
                [TemplateThemeStyle.String] = "\u001b[38;5;0045m",
                [TemplateThemeStyle.Number] = "\u001b[38;5;0200m",
                [TemplateThemeStyle.Boolean] = "\u001b[38;5;0027m",
                [TemplateThemeStyle.Scalar] = "\u001b[38;5;0085m",
                [TemplateThemeStyle.LevelVerbose] = "\u001b[38;5;0239m",
                [TemplateThemeStyle.LevelDebug] = "\u001b[38;5;0013m",
                [TemplateThemeStyle.LevelInformation] = "\u001b[38;5;0006m",
                [TemplateThemeStyle.LevelWarning] = "\u001b[38;5;0011m",
                [TemplateThemeStyle.LevelError] = "\u001b[38;5;0015m\u001b[48;5;0196m",
                [TemplateThemeStyle.LevelFatal] = "\u001b[38;5;0015m\u001b[48;5;0196m",
                // Below are default `Code` theme values
                /*[TemplateThemeStyle.Text] = "\x1b[38;5;0015m",
                [TemplateThemeStyle.SecondaryText] = "\x1b[38;5;0007m",
                [TemplateThemeStyle.TertiaryText] = "\x1b[38;5;0008m",
                [TemplateThemeStyle.Invalid] = "\x1b[38;5;0011m",
                [TemplateThemeStyle.Null] = "\x1b[38;5;0027m",
                [TemplateThemeStyle.Name] = "\x1b[38;5;0007m",
                [TemplateThemeStyle.String] = "\x1b[38;5;0045m",
                [TemplateThemeStyle.Number] = "\x1b[38;5;0200m",
                [TemplateThemeStyle.Boolean] = "\x1b[38;5;0027m",
                [TemplateThemeStyle.Scalar] = "\x1b[38;5;0085m",
                [TemplateThemeStyle.LevelVerbose] = "\x1b[38;5;0007m",
                [TemplateThemeStyle.LevelDebug] = "\x1b[38;5;0007m",
                [TemplateThemeStyle.LevelInformation] = "\x1b[38;5;0015m",
                [TemplateThemeStyle.LevelWarning] = "\x1b[38;5;0011m",
                [TemplateThemeStyle.LevelError] = "\x1b[38;5;0015m\x1b[48;5;0196m",
                [TemplateThemeStyle.LevelFatal] = "\x1b[38;5;0015m\x1b[48;5;0196m",*/
            });
    }
}

appsettings.json

{
  "Serilog": {
    "Using": [ "Serilog.Sinks.Console", "Serilog.Expressions", "MyApp" ],
    "WriteTo": [
      {
        "Name": "Console",
        "Args": {
          "formatter": {
            "type": "Serilog.Templates.ExpressionTemplate, Serilog.Expressions",
            "template": "[{@t:HH:mm:ss} {@l:u3}@{SourceContext}] {#each s in Scope}=> {s} {#delimit}{#end}>> {@m:lj}{#if @x is not null}\n{@x}{#end}\n",
            "theme": "MyApp.TemplateTheme::Literate, MyApp"
          },
        }
      },
    ]
  }
}

The log level is correctly colored, but not the message.

Result image

Sandard template

appsettings.json

{
  "Serilog": {
    "Using": [ "Serilog.Sinks.Console", "Serilog.Expressions", "MyApp" ],
    "WriteTo": [
      {
        "Name": "Console",
        "Args": {
          "outputTemplate": "[{Timestamp:HH:mm:ss} {Level:u3}@{SourceContext}] {Message:lj}{NewLine}{Exception}",
          "theme": "Serilog.Sinks.SystemConsole.Themes.AnsiConsoleTheme::Literate, Serilog.Sinks.Console",
        }
      },
    ]
  }
}

Roughtly the same logs record result: image

nblumhardt commented 2 years ago

@GerkinDev nice scheme! 😎

The problem with your template is the :lj in {@m:lj} - these format specifiers aren't supported by ExpressionTemplate (they've become the default and only option); using just {@m} will give the result you are after.

Would love to see a screenshot of the full theme! :-)

GerkinDev commented 2 years ago

Indeed removing the format fixed it. But the issue still persist for Scope parts, even if I'm not sure formatting should be considered there.

About the theme, as mentioned in comments, the theme is a very slightly modified version of https://github.com/serilog/serilog-sinks-console/blob/f2351f29330fbd0a33bab62bb63b9c358adadb01/src/Serilog.Sinks.Console/Sinks/SystemConsole/Themes/AnsiConsoleThemes.cs#L21-L40.

BTW there should be a normalization of such themes, so that we could convert a theme from Serilog.Sinks.SystemConsole.Themes to a theme valid for this template.

nblumhardt commented 2 years ago

Yeah, not too sure about scope formatting 🤔 - worth investigating.

The unofficial plan I'm working to, though not on any particular timeframe, is for this library to replace all prior filtering/templating/formatting, so we'd no longer need theme support built specifically into Serilog.Sinks.Console. Still a lot of discussion required around that, though.

For the time being, it's nice to have Serilog.Expressions outside of the "core" so that it can evolve and improve in ways we probably wouldn't consider if it were already that low in the dependency graph.

Meligy commented 2 years ago

I'm seeing the same issue also when migrating from AnsiConsoleTheme.Code.

Meligy commented 2 years ago

Actually, removing all formatting strings seems to work. Thanks.

rcdailey commented 1 year ago

I added my thumbs up to this issue, although I'm not sure if votes are effective here.

I will say there are two major issues I ran into that made migration from the default template system to this one challenging:

  1. It wasn't clear to me at first that the existing template syntax wasn't compatible with this new Serilog.Expressions system. I thought the basic elements (like message, level, etc) would work out of the box.
  2. The coloring issue was weird and eventually lead me to this issue.

I think number 1 can be solved with documentation (or if it already exists, I somehow missed it). Number 2 as stated here seems to be broken by using formatters (and as part of the first point, it not being clear that some of them aren't needed, as was the case for @m:lj).

I appreciate the workaround from @nblumhardt!