In Umbraco we use the underlying logging framework of Serilog.

Out of the box, we write a JSON log file that contains a more detailed logfile. This allows tools to perform searches and correlations on log patterns more efficiently.

The default location of this file is written to umbraco/Logs and contains the Machine name, along with the date too:

• umbraco/Logs/UmbracoTraceLog.DELLBOOK.20210809.json

Video overview

Structured logging

Serilog is a logging framework that allows us to do structured logging or write log messages using the message template format. This allows us to have a more detailed log message, rather than the traditional text message in a long txt file.

2021-08-10 09:33:23,677 [P25776/D1/T22] INFO   Umbraco.Cms.Core.Services.Implement.ContentService - Document Home (id=1062) has been published.

Here is an example of the same log message represented as JSON. More information is available and allows you to search and filter logs based on these properties with an appropriate logging system.

{
  "@t":"2021-08-10T08:33:23.6778640Z",
  "@mt":"Document {ContentName} (id={ContentId}) has been published.",
  "ContentName":"Home",
  "ContentId":1062,
  "SourceContext":"Umbraco.Cms.Core.Services.Implement.ContentService",
  "ActionId":"7726d745-d502-4b2d-b55e-97731308041b",
  "ActionName":"Umbraco.Cms.Web.BackOffice.Controllers.ContentController.PostSave (Umbraco.Web.BackOffice)",
  "RequestId":"8000000c-0012-fb00-b63f-84710c7967bb",
  "RequestPath":"/umbraco/backoffice/umbracoapi/content/PostSave",
  "ProcessId":25776,
  "ProcessName":"iisexpress",
  "ThreadId":22,
  "AppDomainId":1,
  "AppDomainAppId":"2f4961977e5c252fa708f7d83915c269b53a620c",
  "MachineName":"DELLBOOK",
  "Log4NetLevel":"INFO ",
  "HttpRequestId":"318b6dd4-b127-4da3-8339-37701f4d1416",
  "HttpRequestNumber":4,
  "HttpSessionId":"0cea7395-ba29-e6c6-93ee-7c08a2fd7219"
}

To learn more about structured logging and message templates you can read more about it over on the https://messagetemplates.org website. Alternatively watch this video from the Serilog creator - https://www.youtube.com/watch?v=OhmNp8UPEEg

Writing to the log

Umbraco writes log messages, but you are also able to use the Umbraco logger to write the log file as needed. This allows you to gain further insights and details about your implementation.

Here is an example of using the logger to write an Information message to the log. It will contain one property, Name, which will output the name variable that is passed into the method.

using Microsoft.AspNetCore.Mvc;
using Microsoft.Extensions.Logging;
using Umbraco.Cms.Web.Common.Controllers;

namespace Umbraco.Cms.Web.UI.NetCore;

public class MyApiController : UmbracoApiController
{
    private readonly ILogger<MyApiController> _logger;

    public MyApiController(ILogger<MyApiController> logger)
    {
        _logger = logger;
    }

    /// /umbraco/api/MyApi/SayHello?name=John
    [HttpGet]
    public string SayHello(string name)
    {
        _logger.LogInformation("We are saying hello to {Name}", name);
        return $"Hello {name}";
    }
}

The incorrect way to log the message would be use string interpolation or string concatenation such as

//GOOD - Do use :)
_logger.LogInformation("We are saying hello to {Name}", name);

//BAD - Do not use :(
_logger.LogInformation($"We are saying hello to {name}");

//BAD - Do not use :(
_logger.LogInformation("We are saying hello to " + name);

The bad examples above will write to the log file, but we will not get a separate property logged with the message. This means we can't find them by searching for log messages that use the message template We are saying hello to {Name}

Log Levels

Serilog uses levels as the primary means for assigning importance to log events. The levels in increasing order of importance are:

1. Verbose - tracing information and debugging minutiae; generally only switched on in unusual situations

2. Debug - internal control flow and diagnostic state dumps to facilitate pinpointing of recognised problems

3. Information - events of interest or that have relevance to outside observers; the default enabled minimum logging level

4. Warning - indicators of possible issues or service/functionality degradation

5. Error - indicating a failure within the application or connected system

6. Fatal - critical errors causing complete failure of the application

Configuration

Serilog can be configured and extended by using the .NET Core configuration such as the AppSetting.json files or environment variables. For more information, see the Serilog config article.

The logviewer dashboard

Learn more about the logviewer dashboard in the backoffice and how it can be extended.

The logviewer desktop app

This is a tool for viewing & querying JSON log files from disk in the same way as the built in log viewer dashboard.

Serilog project/references shipped

Umbraco ships with the following Serilog projects, where you can find further information & details with the GitHub readme files as needed.

• Serilog

• Serilog.AspNetCore

• Serilog.Enrichers.Process

• Serilog.Enrichers.Thread

• Serilog.Expressions

• Serilog.Formatting.Compact

• Serilog.Formatting.Compact.Reader

• Serilog.Settings.Configuration

• Serilog.Sinks.Console

• Serilog.Sinks.File

Further Resources

If you are interested in learning more then the following resources will beneficial:

• Serilog

• Serilog Community Gitter Chatroom

• Nicholas Blumhardt Blog, creator of Serilog

• Serilog Pluralsight Course

• Seq This is free for a single machine such as your own local development computer

During the development of your Umbraco site you can debug and profile the code you have written to analyse and discover bottlenecks in your code.

To perform proper debugging on your site you need to set your application to have debug enabled. This can be done by setting Umbraco:CMS:Hosting:Debug="true" for example in the appsettings.json file:

{
  "Umbraco": {
    "CMS": {
      "Hosting": {
        "Debug": true
      }
    }
  }
}

Tracing

Tracing and trace logging are two names for the same technique. You need to configure which log messages you want to log.

Enabling Trace Logging

We recommend at least logging the following namespace at minimum (Verbose) level to enable valuable trace logging. Thereby you will have information about all endpoints that have been executed.

{
  "Serilog": {
    "MinimumLevel": {
      "Override": {
        "Microsoft.AspNetCore.Mvc": "Verbose"
      }
    }
  }
}

The logged messages can as always be monitored in the log viewer in backoffice

MiniProfiler

Umbraco includes the Mini Profiler project in its core (see https://miniprofiler.com for more details). The MiniProfiler profiles your code method calls, giving you a greater insight into code duration and query time for (for example) underlying SQL queries. It's great for tracking down performance issues in your site's implementation.

Displaying the MiniProfiler

To display the profiler ensure that the configuration Umbraco:CMS:Hosting:Debug is set to true in the appSettings.json file. Thereafter you can add ?umbDebug=true to the query string of any request.

Also, ensure your template calls @Html.RenderProfiler() as one of the last things.

If you click 'Show Trivial' you can seen the kind of detail the MiniProfiler makes available to you about the execution path of your page:

and any underlying SQL Statements that are being executed for a part of the execution:

Writing to the MiniProfiler

If you feel like a part of your application is slow you can use the MiniProfiler in your code to test the speed of it.

All you have to do is inject the IProfiler interface and add a step around your logic:

using Microsoft.AspNetCore.Mvc;
using Microsoft.AspNetCore.Mvc.ViewEngines;
using Microsoft.Extensions.Logging;
using Umbraco.Cms.Core.Logging;
using Umbraco.Cms.Core.Web;
using Umbraco.Cms.Web.Common.Controllers;

namespace MyCustomUmbracoProject;

public class RootController : RenderController
{
    private readonly IProfiler _profiler;

    public RootController(
        IProfiler profiler,
        ILogger<RenderController> logger,
        ICompositeViewEngine compositeViewEngine,
        IUmbracoContextAccessor umbracoContextAccessor)
        : base(logger, compositeViewEngine, umbracoContextAccessor)
    {
        _profiler = profiler;
    }

    public override IActionResult Index()
    {
        // Perform a step
        using (_profiler.Step("Sleep"))
        {
            System.Threading.Thread.Sleep(1000);
        }

        return base.Index();
    }
}

and now in the profiler you can see:

Umbraco Productivity Tool - Chrome Extension

If you are using the Google Chrome browser you can install this Umbraco Productivity Tool Chrome Extension.

This will allow you to quickly switch between debugging with the MiniProfiler, Trace viewer and normal mode.

Logging

Learn how Umbraco writes log files and how you can write to them.