Logging and tracing

Mobiz logging and tracing lead.

Mobiz Platform Logging Handbok

Assumptions

Before we dive into the features of Mobiz logging infrastructure it is important to understand the problems we aim to solve by building a specific infrastructure on top of the generic logging infrastructure provided by .NET and similar platforms.

  • Complex applications require rich, structured logging. Although improved in .NET Core the general practice in logging was writing a line of text to some kind of output along with a severity value. .NET Core adds typed logging structures but still lacks in terms of defining strong patterns for developers to follow. Modern logging requires much more flexible structuring.
  • Avoiding common problematic bottlenecks like unbuffered Console / Stdout logging. Evergrowing log files, etc.
  • Modern logging requires clean APIs for developer to follow and maintain strong patterns. Although it is possible to track multiple different structures for logging, performance metrics, and usage feature tracking using simple ILogger API it is very easy for developers to break such patterns. Modern logging requires strong patterns in the code and clear definition of required attributes.

Logging in the Mobiz Platform - Key features

The logging infrastructure in Mobiz Platform is optimized for structured, advanced logging as required by highly scalable cloud services.

The following key requirements are the focus point of Mobiz Logging infrastructure.

  • It should be easy in code to log structured log messages with rich context information.

    • To support basic logging: Write a string to the log system against a severity (Verbose/Info/Warning/Error)
    • To enable enhancing log records with rich context like: Current User, Active Organization / Membership, Id of external client calling the API, external client version, etc.
    • To enable logging arbitrary .NET objects, anonymous types or structure instances along with each log record.
    • To enable adding tags along with each log record.
  • It should be easy to log structured metrics.

    • Basically to support metrics like standardized by StatsD and utilised by services like DataDog: Counter, Timer, Gauces and Sets.
    • To enable adding tags along with each metric record.
  • It should be easy to track feature usage

    • Logging “feature usage” or “feature tracking” differs from traditional logging in the way logging doesn’t require severity and should be centered around a simply feature identififer. Feature tracking infrastructure should handle multiple times the load and space requirements of the basic logging infrastructure since we can expect high load.
  • It should be easy to route logging traffic to single or multiple logging target

    • Example:
      • Log Errors and Warning log records to Sentry.
      • Log Errors and Warning and Info to Datadog via buffered stdout writer.
      • Log Metrics to DataDog via DogStatsD service.
      • Log Feature tracking to Elastic Search.

Key concepts and usage examples

The following services provide the above defined infrastructure:

  • Mobiz.Core.Log.IMobizLogger
  • Mobiz.Core.Log.IMobizMetricsLogger
  • Mobiz.Core.Log.IMobizFeatureTrackingLogger

Logging Services can be accessed via standard .NET DI injection.

In addition the MobizServiceCollection provides direct properties for accessing the services.

Code Example showcasing MobizServiceCollection log service accessor API

 var msc = MobizServiceCollection.Default;
 var logger = msc.Logger;
 var metricsLogger = msc.Metrics;
 var featureTrackingLogger = msc.FeatureTracking;

Code Example using the basic logging infrastructure:

// Access IMobizLogger instance and log basic error message:
var logger = mobizServiceCollection.Logger;
logger.Log("Something terrible happened!", TraceLevel.Error);

// Log error message with full context details and tags:
logger.Log("Something terrible happened!", TraceLevel.Error,
    // All arguments below are optional
    userId: myUserId,
    organizationId: myOrganizationId,
    source: "My feature name",
    clientId: "client",
    clientVersion: "1.0.0",
    error: ex,
    tags: new[] {"tag1", "tag2"},
    keyValueArgs: new Args
    {
        {"key1", "value1"},
        {"key2", "value2"},
        {
            "Anonymous type", new { Id = 1, FirstName = "James", LastName = "Bond" }
            
        }

    });

// Log error as above but use Builder pattern instead for clarity:
logger.LogBuilder("Something terrible happened!", TraceLevel.Error)
    .User(myUserId)
    .Organization(myOrganizationId)
    .Source("My feature name")
    .Client("client", "1.0.0.0")
    .Error(ex)
    .Tags(new[] {"tag1", "tag2"})
    .Args(new Args
    {
        {"key1", "value1"},
        {"key2", "value2"},
        {
            "Anonymous type", new { Id = 1, FirstName = "James", LastName = "Bond" }
            
        }
    })
    .Submit();

// Log using IOrganizationContext instance instead of userId + organization Id:
logger.Log("Something interesting happened!", TraceLevel.Info,
    organizationContext);

Code example showcasing Metrics logging API

Note: Metric types are based on StatsD metrics definition. See information here: https://github.com/statsd/statsd/blob/master/docs/metric_types.md

var metricsLogger = mobizServiceCollection.Metrics;
// Set counter value
metricsLogger.Counter("myMetric", 1000);
// Increment counter by 1 (default) + with tags
metricsLogger.Increment("myMetric",
    tags: new[] {"tag1","tag2"});
// Decrement counter
metricsLogger.Decrement("myMetric");
// Set Gauge Value
metricsLogger.Gauge("LoadPercent", 98);
// Update Histogram Value
metricsLogger.Histogram("LoadingProgress", 200);
// Set Timer Value
metricsLogger.Timer("LoginTimer", 35);

Code example showcasing Feature tracking API

var tracker = mobizServiceCollection.FeatureTracking;
tracker.LogFeatureUsage("ListDocument",
    userId: myUserId,
    clientId: "RecordsApp",
    clientVersion: "1.2.0.1",
    // Below arguments are optional
    organizationId: myOrganizationId,
    tags: new[] {"tag1", "tag2"},
    keyValueArgs: new Args
    {
        {"key1", "value1"},
        {"key2", "value2"},
        {
            "Anonymous type", new { Id = 1, FirstName = "James", LastName = "Bond" }
            
        }

    });

Notice from above code example how similar general logging and feature tracking may look API wise. The way we want to route, classify and manage the results is very different making it important to draw a clear line between the two concepts API wise.

Feature tracking serves the purpose of tracking usage data and to analyse business value delivered by features while logging is for tracking the internals of the system,detecting and analysing problems.

Code example showcasing typical configuration from Code

"MobizLogConfig": {
        "Providers": [
            {
                "ProviderId": "Sentry",
                "LogLevel": "Warning",
                "Logging": true,
                "FeatureTracking": false,
                "Metrics": false
            },
            {
                "ProviderId": "Console",
                "LogLevel": "Info",
                "Logging": true,
                "FeatureTracking": true,
                "Metrics": false
            },
            {
                "ProviderId": "DataDog",
                "Logging": false,
                "FeatureTracking": false,
                "Metrics": true
            }
        ]
    }

Working with the logging API

When Working with the logger API directly developer has to be aware of key arguments and their usage.

Source

Name / Identifier for the part of the code which the logging record originates. This is useful for tracing log messages.

  • Source is an argument available for log messages only.
  • Source is not available for Metrics nor Feature tracking.

ClientId & ClientVersion

Mobiz external API Authorization mechanism requires HTTP Header Arguments for client and client-id.

By enforcing this we assure that the backend has context about the caller in terms of what client is actually calling our API and which version.

In case of internal functions, triggered by SYSTEM those values can be left as default = null.

  • Client information is optional argument for logging and feature tracking.
  • Client information can not be logged with Metrics.

UserId / OrganizationId

Mobiz security infrastructure is based around “scope”, i.e. that code is always running within a given security scope which has limited visibility in terms of data and functionality.

Mobiz Scope can be:

  • SystemScope
    • Code is executing as part of internal, system logic which is not running on behalf of any customer or customer account logic.
  • UserScope
    • Code is executing as part of User triggered logic which does NOT belong to Organization information.
  • OrganizationScope
    • Code is executing as part of logic related to Organization. Organization scope always INCLUDES a UserScope since Organization is accessed by User via Membership.

The

  • Scope information is optional argument for Log messages and Feature Tracking.
  • Scope information can not be logged with Metrics.

Args: arbitrary structured data

  • Args is an optional argument for logging and feature tracking.
  • Args can not be logged with Metrics.
  • Args is essentially a thin wrapper for Dicationary<string, object> type.
  • Any object provided as Args value will be serialized to JSON. Be careful when using objects which might have reference to complext types which will be serialized along with the passed object instance.

Tags

  • Tags are available as logging options for Log messages, feature tracking and metrics.
  • Tags are provided as string array.

Error

  • Log Message API has optional error argument for accepting an Exception representing an active error.
  • Exception instances can be sent along with error message when logging.
  • Error is not available for feature tracking nor metrics.
  • Exception will be sent directly to each target logging library which will handle breaking down and extracting error information into multiple properties with rich details.

Available Log Providers

Sentry

Provides support for Sentry log management service. www.sentry.io

Sentry log target uses Sentry client library directly. https://docs.sentry.io/platforms/dotnet/

Supported log types:

  • General logging
  • Feature tracking

Not supported

  • Metrics

Required Configuration

  "Sentry": {
    "DSN": "",
    "ErrorTrackPage": "https://sentry.io/organizations/code-north-ehf/issues/?query="
  }

Exceptionless

Provides support for Exceptionless log management service. www.https://exceptionless.com/

Exceptionless log target uses Exceptionless client library directly. https://exceptionless.com/docs/clients/dotnet/configuration/#configuring-with-code

Supported log types:

  • General logging
  • Feature tracking

Not supported

  • Metrics

Required Configuration

"Exceptionless": {
    "ErrorTrackPage": "https://be.exceptionless.io/event/by-ref/",
    "ApiKey": ""
  }

Console / STDOUT

Console target wil write log message to buffer which is flushed periodically to STDOUT.

  • Buffered Console logger will flush STDOUT every 15 seconds.
  • In case of error the message is flushed without buffering.

JSON Structure is based on DataDog definition for reserved attributes:

  1. https://docs.datadoghq.com/logs/log_collection/?tab=host#attributes-and-tags
  2. https://docs.datadoghq.com/logs/log_configuration/attributes_naming_convention/

JSON structures

JSON Structure for Log message

{
  "type": "log";
  "logger.name": "LOGGER NAME",
  "logger.thread_name": "MSG THREAD NAME/ID",
  "timestamp": "2008-09-22T14:01:54.9571247Z",
  "message: "LOG MESSAGE",
  "level": "LOG LEVEL: Error, Warning, Info, Verbouse",
  "userId": "ACTIVE MOBIZ USER ID",
  "organizationId" "ACTIVE MOBIZ ORGANIZATION ID",  
  "source": "LOG MESSAGE SOURCE",
  "clientId": "REST API CLIENT ID",
  "clientVersion": "REST API CLIENT VERSION",
  "error.stack": "ERROR STACK TRACE",
  "error.kind": "ERROR KIND",
  "error.exception": "ERROR EXCEPTION INSTANCE",
  "tags": string[]
  "keyValueArgs":  dictionary
 }

JSON Structure for Metrics message

// Counter
{
   "type": "log.metrics.counter",
   "timestamp": "2008-09-22T14:01:54.9571247Z",
   "name": "COUNTER NAME",
   "value": COUNTER__VALUE_NUM,
   "sampleRate": VALUE_SAMPLE_RATE_FLOAT,
   "tags": string[]
}
// Counter Increment
{
   "type": "log.metrics.counter.increment",
   "timestamp": "2008-09-22T14:01:54.9571247Z",
   "name": "COUNTER NAME",
   "value": COUNTER_INCREMENT_VALUE_NUM,
   "sampleRate": VALUE_SAMPLE_RATE_FLOAT,
   "tags": string[]
}
// Counter Decrement
{
   "type": "log.metrics.counter.decrement",
   "timestamp": "2008-09-22T14:01:54.9571247Z",
   "name": "COUNTER NAME",
   "value": COUNTER_DECREMENT_VALUE_NUM,
   "sampleRate": VALUE_SAMPLE_RATE_FLOAT,
   "tags": string[]
}
// Gauge
{
   "type": "log.metrics.gauge",
   "timestamp": "2008-09-22T14:01:54.9571247Z",
   "name": "GAUGE NAME",
   "value": GAUGE_VALUE_NUM,
   "sampleRate": VALUE_SAMPLE_RATE_FLOAT,
   "tags": string[]
}
// Histogram
{
   "type": "log.metrics.histogram",
   "timestamp": "2008-09-22T14:01:54.9571247Z",
   "name": "HISTOGRAM NAME",
   "value": HISTOGRAM_VALUE_NUM,
   "sampleRate": VALUE_SAMPLE_RATE_FLOAT,
   "tags": string[]
}
// Timer
{
   "type": "log.metrics.timer",
   "timestamp": "2008-09-22T14:01:54.9571247Z",
   "name": "TIMER NAME",
   "value": TIMER_VALUE_NUM,
   "sampleRate": VALUE_SAMPLE_RATE_FLOAT,
   "tags": string[]
}
// Set
{
   "type": "log.metrics.set",
   "timestamp": "2008-09-22T14:01:54.9571247Z",
   "name": "SET NAME",
   "value": SET_VALUE_NUM / STRING,
   "sampleRate": VALUE_SAMPLE_RATE_FLOAT,
   "tags": string[]
}       

JSON Structure for Feature Tracking message

{
  "type": "log.usage";
  "timestamp": "2008-09-22T14:01:54.9571247Z",
  "feature: "FEATURE_ID",
  "userId": "ACTIVE MOBIZ USER ID",
  "organizationId" "ACTIVE MOBIZ ORGANIZATION ID",  
  "clientId": "REST API CLIENT ID",
  "clientVersion": "REST API CLIENT VERSION",
  "tags": string[]
  "keyValueArgs":  dictionary
 }

Supported log types:

  • General logging
  • Feature tracking
  • Metrics

Required Configuration

  • None

ElasticLogger will route log to automatically created, period based indexes in Elastic Search.

ElasticLogger supports buffered writing against ElasticSearch to reduce network overhead. The logger will automatically create an index for every month following the naming pattern: “mobizlog-YYYY-mm”.

Also the logger will create two aliases which can be used to query over greater set of the logging data:

  • mobizlog-all => Alias containing all indexes containing log data.
  • mobizlog-recent => Alias containing latest 6 months of indexed log data.

Supported log types:

  • General logging
  • Feature tracking
  • Metrics

Required Configuration

  • Currently ElasticLogger will utilize the same Elastic Search cluster as is used for other indexing purposes of the Mobiz Platform. Therefore no extra configurations are required.

Elastic Search Data Model

Log messages, Feature tracking and Metrics logs are written to the same index.

The structure of the log records is as follows:

/// <summary>
    /// Index document for holding log entries.
    /// </summary>
    public class MobizElasticLogLine
    {
        /// <summary>
        /// Log line timestamp.
        /// </summary>
        public DateTime Timestamp { get; set; }
        /// <summary>
        /// Log line type. Options: "Log", "Metric", "Usage".
        /// </summary>
        public string LineType { get; set; }
        /// <summary>
        /// User identifier associated with event.
        /// </summary>
        public Guid UserId { get; set; }
        /// <summary>
        /// Organization identifier associated with event.
        /// </summary>
        public Guid OrganizationId { get; set; }
        /// <summary>
        /// Application source triggering event.
        /// </summary>
        public string Source { get; set; }
        /// <summary>
        /// Logged in user / authorized client identifier. 
        /// </summary>
        public string ClientId { get; set; }
        /// <summary>
        /// Logged in user / authorized client version. 
        /// </summary>
        public string ClientVersion { get; set; }
        /// <summary>
        /// Error details.
        /// </summary>
        public string Error { get; set; }
        /// <summary>
        /// Key value arguments.
        /// </summary>
        public Dictionary<string,object> Args { get; set; } 
        /// <summary>
        /// Tags.
        /// </summary>
        public string[] Tags { get; set; }
        /// <summary>
        /// Metric details: Type of metric.
        /// </summary>
        public string MetricType { get; set; }
        /// <summary>
        /// Metric details: Metric name.
        /// </summary>
        public string MetricName { get; set; }
        /// <summary>
        /// Metric details: Metric numerical value.
        /// </summary>
        public double NumValue { get; set; }
        /// <summary>
        /// Metric details: Metric string value.
        /// </summary>
        public string StringValue { get; set; }
        /// <summary>
        /// Metric details: Metric sample rate.
        /// </summary>
        public double SampleRate { get; set; }
        /// <summary>
        /// Feature tracking: feature name.
        /// </summary>
        public string Feature { get; set; }
        /// <summary>
        /// Generic logging: Message.
        /// </summary>
        public string Message { get; set; }
        /// <summary>
        /// Generic logging: Log level.
        /// </summary>
        public string Level { get; set; }
        /// <summary>
        /// Thread identifier of logging code.
        /// </summary>
        public string ThreadName { get; set; }
    }

DataDog

Logger which routes messages directly to DataDog using the DogStats service provided by the DataDog APM client.

Supported log types:

  • General logging
  • Metrics

Not supported

  • Feature tracking

Required Configuration

  • TODO

Notes on DataDog logger

The logger is currently considered experimental. For new we suggest to rather utilise the Console logger for writing structured JSON to STDOUT which DataDog can ingest and process in highly structured manner.

Strategies and utilities for logging with rich context information.

Logging Extension Methods in Mobiz.Core.Web. Extensions

Mobiz.Core.Web.Extensions namespace provides utility extensions simplifying the logging API, especially by encapsulating extraction of client information, environment, client-id, version, etc.

The extension methods provide simpler API compared to the bare APIs, taking care of client context details as well as adding environment information, client information and related details to the log messages when such information are available.

Extra information gathered and added as argument by extension methods (If available)

  • ClientAgent: Full User-Agent path.
  • ClientIP: Client IP address.
  • URL: Request absolute URL.
  • ClientOS: Client operating system.
  • ImpersonationLoginId: Id of impersonation login (Impersonation session only)
  • ImpersonationAuthorizationId: Id of impersonation session authorization (Impersonation session only)
  • ImpersonatingAdminUserId: Id of the Admin user impersonating the active user (Impersonation session only)

Methods:

  • LogMessage (IUserContext)
  • LogMessage (IOrganizationContext)
  • LogMessageAsHttpContextUser (HttContext)
  • LogMessageAsCurrentHttpContextUser
  • LogError (IUserContext)
  • LogError (IOrganizationContext)
  • LogErrorHttpContextUser (HttContext)
  • LogErrorAsCurrentHttpContextUser
  • LogFeatureUsage (IUserContext)
  • LogFeatureUsage (IOrganizationContext)
  • LogFeatureUsageAsHttpContextUser (HttContext)
  • LogFeatureUsageAsCurrentHttpContextUser

Client logging via Logger REST API Endpoint

Mobiz Platform provides an endpoint for utilising the logging infrastructure from external clients.

This is provided by a logging endpoint:

/api/v1/logger

The logger endpoint accepts batch of logging messages via POST method including a body containing a model defined as Mobiz.Core.Web.Models.BatchLogModel

   /// <summary>
    /// Model for posting a batch of log records from client.
    /// </summary>
    public class BatchLogModel
    {
        /// <summary>
        /// Organization id.
        /// </summary>
        public Guid OrganizationId   { get; set; }
        /// <summary>
        /// Log source.
        /// </summary>
        public string Source   { get; set; }
        /// <summary>
        /// Log messages.
        /// </summary>
        public List<LogMessage> LogMessages   { get; set; }
        /// <summary>
        /// Feature tracking / usage log lines.
        /// </summary>
        public List<FeatureTrackingMessage> FeatureTrackingMessages   { get; set; }
        /// <summary>
        /// Metrics tracking log lines.
        /// </summary>
        public List<MetricsMessage> MetricsMessages   { get; set; }
    }

    /// <summary>
    /// Model for returning results from batch logging request.
    /// </summary>
    public class BatchLogResponse
    {
        /// <summary>
        /// Number of posted messages.
        /// </summary>
        public int MessagePosted { get; set; }
        /// <summary>
        /// If problems encountered they will be listed here.
        /// </summary>
        public List<string> MessageProblems { get; set; }
    }

    /// <summary>
    /// Represents a single logging message.
    /// </summary>
    public class LogMessage
    {
        /// <summary>
        /// Log text message.
        /// </summary>
        public string Message   { get; set; }
        /// <summary>
        /// Log level.
        /// </summary>
        public TraceLevel LogLevel  { get; set; }
        /// <summary>
        /// Optional key/value arguments.
        /// </summary>
        public Dictionary<string, JToken> KeyValueArgs  { get; set; }
        /// <summary>
        /// Optional tags.
        /// </summary>
        public List<string> Tags  { get; set; }
    }

    /// <summary>
    /// Represents a single feature tracking message.
    /// </summary>
    public class FeatureTrackingMessage
    {
        /// <summary>
        /// Feature name.
        /// </summary>
        public string Feature { get; set; }
        /// <summary>
        /// Optional key/value arguments.
        /// </summary>
        public Dictionary<string, JToken> KeyValueArgs  { get; set; }
        /// <summary>
        /// Optional tags.
        /// </summary>
        public List<string> Tags  { get; set; }
    }

    /// <summary>
    /// Supported metric types.
    /// </summary>
    public enum MetricTypes
    {
        Count = 1,
        Gauge = 2,
        Histogram = 3,
        Set = 4
    }

    /// <summary>
    /// Represents a single metrics tracking message.
    /// </summary>
    public class MetricsMessage
    {
        /// <summary>
        /// Metric type:  Count, Gauge, Histogram, Set
        /// </summary>
        public MetricTypes MetricType { get; set; }
        /// <summary>
        /// Metric name.
        /// </summary>
        public string MetricName { get; set; }
        /// <summary>
        /// Metric value.
        /// </summary>
        public JToken Value { get; set; }
        /// <summary>
        /// Tags.
        /// </summary>
        public List<string> Tags  { get; set; }                
    }

Message received by the endpoint will be logged via Mobiz log infrastructure and routed according to configurations. Log messages received via the /api/v1/logger endpoint will have a tag added: “LoggerApi”.