Skip to content

Understanding Logging

Oleg Karasik edited this page Dec 4, 2019 · 7 revisions

Because not all services components are necessary aware of the exact execution environment ex. the ASP.NET controller can be in a shared assembly that could be used in Service Fabric project as well as in the other ASP.NET projects the CoherentSolutions.Extensions.Hosting.ServiceFabric has integration with Microsoft.Extensions.Logging that is able to redirect all events written using ILogger<T> interface to event source (ETW).

All services with no exception has event source - by default it is self-descriptive event source created at runtime with (application type name).(service type name) name.

This can be customized by configuring event source

Configuring logging redirection

The log redirection is disabled by default and should be enabled manually. You can enable log redirection for endpoints, event handlers and background jobs. This can be done using UseLoggerOptions(...) method by passing in a factory function that returns an instance of IServiceHostLoggerOptions with IServiceHostLoggerOptions.LogLevel different from None.

public interface IServiceHostLoggerOptions
{
  // The level of events to redirect.
  //
  // Please see: https://docs.microsoft.com/en-us/dotnet/api/microsoft.extensions.logging.loglevel?view=aspnetcore-2.1
  LogLevel LogLevel { get; }

  // Indicates whether metadata items set as ILogger.BeginScope<TState>(...)
  // should be transforment to string and included in the event entry.
  //
  // Each nested call to ILogger.BeginScope<TState>(...) will result in a
  // new line sin metadata string.
  bool IncludeMetadata { get; }

  // Indicates whether exception stacktrace should be included in the event entry.
  bool IncludeExceptionStackTrace { get; }
}
new HostBuilder()
  .DefineStatefulServiceHost(
    serviceBuilder =>
    {
      serviceBuilder
        .DefineDelegate(
          delegateBuilder =>
          {
            delegateBuilder
              .UseLoggerOptions(() => { ... });
          })
        .DefineAspNetCoreListener(
          listenerBuilder =>
          {
            listenerBuilder
              .UseLoggerOptions(() => { ... });
          })
        .DefineRemotingListener(
          listenerBuilder =>
          {
            listenerBuilder
              .UseLoggerOptions(() => { ... });
          })
        .DefineGenericListener(
          listenerBuilder =>
          {
            listenerBuilder
              .UseLoggerOptions(() => { ... });
          });
    });

Infrastructure provide an implementation of IServiceHostListenerLoggerOptions in form of ServiceHostListenerLoggerOptions. The implementation has the following defaults: LogLevel = LogLevel.Information, IncludeMetadata = true and IncludeExceptionStackTrace = true.

Writing events using ILogger

The events are written using existing ILogger<T> API. The EventCategory is automatically set when ILogger<T> is obtained while EventName (if required) should be set explicitly using EventId structure.

var logger = context.RequestServices.GetService<ILogger<Startup>>();

logger.LogInformation(new EventId(-1 /* This value is ignored */, "My Event"), "My Message");

The Id is ignored because in case when underlying event source is self-descriptive then Id is ignored by the ETW infrastructure (see Vance Morrison comment and in case when underlying event source was reconfigured) then what events are written is decided by the underlying implementation.

Because there are no one to one mapping between LogLevel used by ILogger<T> and EventLevel the infrastructure use the following mapping:

EventLevel LogLevel
Critical Critical
Error Error
Warning Warning
Information Informational
Verbose Trace, Debug
LogAlways -

The structure of event entry depends on whether event source was or wasn't reconfigured. In case when default implementation is used then all entries have common structure:

{
  "Timestamp": "2018-06-11T12:48:27.5708317+03:00",
  "ProviderName": "AppType.StatefulServiceType", // Name of the event source (application type name).(service type name)
  "Id": 698,       
  "Message": null,                                 
  "ProcessId": 13824,
  "Level": "Informational",
  "Keywords": "0x0000000000000001", // All events written by ILogger are bound to the same keyword
  "EventName": "My Event",
  "ActivityID": null,
  "RelatedActivityID": null,
  "Payload": {
    "EventId": 10,
    "EventName": "My Event",
    "EventCategoryName": "StatefulService.Startup",
    "EventMessage": "My Message",
    "EventStackTrace": "", // Exception stack trace.
    "EventMetatada": "", // Metadata
    "ServiceName": "fabric:/App/StatefulService",
    "ServiceTypeName": "StatefulServiceType",
    "ReplicaOrInstanceId": 131731839104813560,
    "PartitionId": "\"e2785724-b5df-4dd0-ad90-dc3f97cdc97e\"",
    "ApplicationName": "fabric:/App",
    "ApplicationTypeName": "AppType",
    "NodeName": "_Node_2"
  }
}

Depending on the source of events the Payload can have additional fields ex. if events are written by ASP.NET Core listener then Payload will have additional EndpointName field.