sumo serilog appender failing to substitute template string variables

[eddit0r]

A sumo customer has an issue implementing the sumo serilog appender.

The sumo appender is not substituting variables as expected.

The standard serilog console logger is performing the substitutions as expected.

The customer suspects a template issue:

example of failed substitution.
_messageLogger.Error("{name} - Failed to publish a message, RequestId:{correlationId}, HttpResponseMessage: {httpResponse}", "PublishCandidate", requestId, errorMessage);

It is hooked up to the sumo driver in the following way :

logger = new LoggerConfiguration() 
.WriteTo.RollingFile(log["LogFilePath"].ToString()) 
.MinimumLevel.Information() 
.MinimumLevel.Override("Microsoft", LogEventLevel.Warning) 
.Enrich.FromLogContext() 
.WriteTo.Console() 
.WriteTo.BufferedSumoLogic( 
new Uri(sumoConfig["MessageLogContainerUrl"]), 
sourceName: sumoConfig["MessageLogSourceName"], 
sourceCategory: sumoConfig["MessageLogSourceCategory"], 
formatter: new CompactJsonFormatter()) 
.CreateLogger();

[bin3377]

@wdolek any comment on this?

[eddit0r]

Customer reports sumo serilog driver throwing exception under load, see stack trace attached.

[wdolek]

@eddit0r Sorry for such delay in response, completely missed notification.

From how you described the issue, I'm not really sure what could be the cause - template seems to be OK, we are using logging similar way without any problem. I can try to debug, but no promise. (Yet I'm puzzled that it works as expected with just console sink)

Regarding exception thrown and its stack trace, I would assume that this is between SumoLogic server and client - as you can see, common SumoLogic code is used to send events. What does under load mean in your case? Would it be possible to try with different logging framework (NLog?) under same load?

[wdolek]

@eddit0r I realized I might misunderstand your issue regarding replacing. I think what you see is intentional.

Let's say I log message with this template:
Request to {RequestUri}, Status: {StatusCode}, Duration: {Duration} ms

This is what I get in SumoLogic:

{
  "Timestamp": "2019-01-01T00:00:00.0000000Z",
  "Message": "Request to {RequestUri}, Status: {StatusCode}, Duration: {Duration} ms",
  "Level": "Information",
  "RequestUri": "https://localhost",
  "StatusCode": "200",
  "Duration": 1.000000000000001,
  "SourceContext": "MyService",
  "HttpMethod": "GET",
  "Uri": "https://localhost",
  "ActionId": "00000000-0000-0000-0000-000000000000",
  "ActionName": "MyEndpoint",
  "RequestId": "0000000000000:00000000",
  "RequestPath": "/v1/dummy",
  "CorrelationId": "00000000-0000-0000-0000-000000000000",
  "ConnectionId": "0000000000000",
  "Scope": [
    "HTTP GET https://localhost"
  ]
}

... so yes, Message does not contain replaced values - but it's actually OK - you can use it as key for lookup. Values are then set as properties (matching placeholder names) of JSON representing event. You can use these for search, creating graphs, ...

Did this help you? Are you expecting message to be replaced? @bin3377 is this how it is supposed to work?

[bin3377]

For me, keeping value of "Message" field with the same result as console logger (e.g., with replaced value) sounds more reasonable. People can actually only extract "Message" for the essential information they needed. thought?

[eddit0r]

@wdolek I think the customers expectation is that the substitution would function as the console loggers did. Unfortunately I am relaying this detail secondhand.

[wdolek]

@eddit0r, so after all it's not issue of library - it's by design of Serilog JsonFormatter and CompactJsonFormatter (which you are using). In order to get placeholders replaced, please use RenderedCompactJsonFormatter or implement own custom formatter (more about formatting here: Serilog/Formatting Output).

Let us know whether this helped.