Copied to clipboard

Flag this post as spam?

This post will be reported to the moderators as potential spam to be looked at


  • Warren Buckley 2082 posts 4489 karma points MVP 6x admin hq c-trib
    Aug 16, 2018 @ 19:12
    Warren Buckley
    2

    Umbraco Logging - Switching from Log4Net to Serilog

    Hello,
    As an evening pet hack project I have decided to replace Log4Net in Umbraco out with Serilog in version 8.

    Why change it?

    For some people, you may think 'Why are you changing it' when there is nothing wrong with it. Yes it does work just OK, but with part of Umbraco's goal of making things better, I think it could be improved a lot more.

    With a logging framework such as Log4Net it outputs log messages be it to a .TXT file or into a database as a single string such as

    2018-08-16 13:44:27,617 [P25420/D2/T1] INFO  Umbraco.Core.PluginManager - Resolved umbraco.interfaces.IDiscoverable (took 352ms)
    

    There is no easy way to search for items in the logfile or common patterns unless you love RegEx, which I for one don't.

    So in comparison Serilog uses Message Templates - https://messagetemplates.org to create structured logging, which allows us to store properties with the log message, which allows us to query and search log entries a lot easier.

    For example the same log message above could have the following properties

    • Log Level - INFO
    • Process ID - 25420
    • Thread ID - 1
    • App Domain ID - 2
    • Duration - 352
    • Type - umbraco.interfaces.IDiscoverable

    So depending on how or where we store our log files, be it in a database table, third party tool such as SEQ. We will know have the power to find & query log items a lot easier.

    • Find me all log entires where the Thread ID is 1
    • Find me all log entries where the duration is greater than 400ms
    • etc..

    Proposed PR

    I have a PR that is pretty much finished and awaiting some feedback internally, but I wanted to discuss the changes I have done here, to get the community's feedback and input to ensure this is something the Umbraco community will benefit from & find useful.

    https://github.com/umbraco/Umbraco-CMS/pull/2845

    So my PR configures Serilog as the default logging framework that will output the following out of the box:

    • The same .TXT file output as before, in case you use any fancy RegEx tools or similar in your workflow
    • A JSON log file that outputs the string message along with the properties, making something a tool can use to search on

    An example of the JSON output is as follows:

    {"@t":"2018-08-14T10:35:57.1049995Z","@mt":"[Timing {TimingId}] {EndMessage} ({TimingDuration}ms)","TimingId":"f4858608-654f-46bb-ab55-8d870d86069d","EndMessage":"Resolved.","TimingDuration":340,"SourceContext":"Umbraco.Core.Runtime.CoreRuntime","ProcessId":1052,"ProcessName":"iisexpress","ThreadId":1,"AppDomainId":2,"AppDomainAppId":"LMW3SVC2ROOT","Log4NetLevel":"INFO "}
    

    For readability (as opposed to single line)

    {
        "@t": "2018-08-14T10:35:57.1049995Z",
        "@mt": "[Timing {TimingId}] {EndMessage} ({TimingDuration}ms)",
        "TimingId": "f4858608-654f-46bb-ab55-8d870d86069d",
        "EndMessage": "Resolved.",
        "TimingDuration": 340,
        "SourceContext": "Umbraco.Core.Runtime.CoreRuntime",
        "ProcessId": 1052,
        "ProcessName": "iisexpress",
        "ThreadId": 1,
        "AppDomainId": 2,
        "AppDomainAppId": "LMW3SVC2ROOT",
        "Log4NetLevel": "INFO "
    }
    

    One benefit is that this JSON file can be imported into a tool called SEQ, which is free for single user local development, allowing you to create complex queries and visually see your logs and any occurring patterns.

    With Serilog it's easy to configure and extend to get logs stored somewhere else, which are known as Sinks in Serilog, which could also log messages into a database, ELMAH.IO, SEQ or many more tools or services.

    The configuration of this can be achieved with a new proposed serilog.user.config file. Below is an example of configuring Serilog to create a custom log file for us, that only includes our custom namespace. Useful if you wanted to keep your log entries somewhere separate.

    <?xml version="1.0" encoding="utf-8" ?>
    <configuration>
        <appSettings>
    
            <!-- Controls log levels for all user-definied child sub-logger sinks configured here (Set this higher than child sinks) -->
            <add key="serilog:minimum-level" value="Verbose" />
    
            <!-- For Different Namespaces - Set different logging levels -->
            <add key="serilog:minimum-level:override:Microsoft" value="Warning" />
            <add key="serilog:minimum-level:override:Microsoft.AspNetCore.Mvc" value="Error" />
            <add key="serilog:minimum-level:override:YourNameSpace" value="Information" />
    
            <!-- All logs definied via user.config will contain this property (won't be in main Umbraco logs) -->
            <add key="serilog:enrich:with-property:websiteName" value="Warrens Website" />
    
            <!-- Write to a user log file -->
            <add key="serilog:using:File" value="Serilog.Sinks.File" />
            <add key="serilog:write-to:File.path" value="%BASEDIR%\logs\warren-log.txt" />
            <add key="serilog:write-to:File.restrictedToMinimumLevel" value="Debug" /> <!-- I will be ignored as Debug as the user logging pipleine has it min set to Information, so only Info will flow through me -->
            <add key="serilog:write-to:File.retainedFileCountLimit" value="32" /> <!-- Number of log files to keep (or remove value to keep all files) -->
            <add key="serilog:write-to:File.rollingInterval" value="Day" /> <!-- Create a new log file every Minute/Hour/Day/Month/Year/infinite -->
    
            <!-- Filters all above sink's to use this expression -->
            <!-- Common use case is to include SourceType starting with your own namespace -->
            <add key="serilog:using:FilterExpressions" value="Serilog.Filters.Expressions" />
            <add key="serilog:filter:ByIncluding.expression" value="StartsWith(SourceContext, 'Umbraco.Core')" />
    
        </appSettings>
    </configuration>
    

    I want to hear from you...

    I would love to hear from you, the wider Umbraco community to hear about your different logging needs. Do you do something currently complex or very custom with Log4Net. If so I would love to hear about it and ensure that these scenarios can still be achieved.

  • Dave Woestenborghs 3189 posts 10602 karma points MVP 3x admin c-trib
    Aug 17, 2018 @ 09:45
    Dave Woestenborghs
    1

    Hi Warren,

    If logs are easier searchable than go for it.

    can you also have different log levels for different assemblies. That is now possible with log4net.

    And I would like to have a log viewer in the backend. Now we need to install diplo log viewer on all our non cloud projects.

    Dave

  • Warren Buckley 2082 posts 4489 karma points MVP 6x admin hq c-trib
    Aug 17, 2018 @ 09:53
    Warren Buckley
    0

    Hi Dave, Yes in the Serilog.user.config sample above this snippet will control log levels for different namespaces.

    <!-- For Different Namespaces - Set different logging levels -->
    <add key="serilog:minimum-level:override:Microsoft" value="Warning" />
    <add key="serilog:minimum-level:override:Microsoft.AspNetCore.Mvc" value="Error" />
    <add key="serilog:minimum-level:override:YourNameSpace" value="Information" />
    

    And I am considering if we can make something ship in the core of Umbraco 8 to be a log viewer - but we will have to wait and see in regards to that.

  • jeffrey.schoemaker@perplex.nl 294 posts 1167 karma points MVP 2x c-trib
    Aug 17, 2018 @ 13:58
    jeffrey.schoemaker@perplex.nl
    1

    Hi Warren,

    I haven't tried this piece of code out, but I think it should be doable to save everything into the database into seperate fields: https://logging.apache.org/log4net/release/config-examples.html.

    For my CG18 Security-presentation I wanted to log Umbraco-authentication-events to Windows Event Viewer instead of only to the default .txt-files and that was a piece of cake (slide 123: https://www.perplex.nl/media/107928/codegarden-18-umbraco-security.pdf).

    Maybe it's some inspiration, have a great weekend!

    Jeffrey

  • Warren Buckley 2082 posts 4489 karma points MVP 6x admin hq c-trib
    Aug 17, 2018 @ 14:35
    Warren Buckley
    0

    Hi Jeffery.
    For logging the same log messages to Windows Event Log can be done with the Serilog Sink.

    https://github.com/serilog/serilog-sinks-eventlog

    In regards to saving it to the Database this is also doable and I am currently thinking this may become default if we do some kind of built in log viewer in Umbraco 8

    https://github.com/serilog/serilog-sinks-mssqlserver

    So for those two scenarios we have the possibility to get those two bases covered for you.

    Warren

  • jeffrey.schoemaker@perplex.nl 294 posts 1167 karma points MVP 2x c-trib
    Aug 17, 2018 @ 14:47
    jeffrey.schoemaker@perplex.nl
    0

    Hi Warren,

    thanks but if Log4Net supports storing in the database, why would you replace it with Serilog? What does Serilog do more than Log4Net

    Regards Jeffrey

    ps: I do not want to encourage you to research this or implement this :P

  • Warren Buckley 2082 posts 4489 karma points MVP 6x admin hq c-trib
    Aug 17, 2018 @ 14:55
    Warren Buckley
    0

    Hiya
    Maybe my original post is not very clear but the difference between the Log4Net approach & Serilog, is that Log4Net will only generate the formatted message in the log and you have no way of easily searching parts of a log message.

    So with the message template for Serilog

    [Timing {TimingId}] {EndMessage} ({TimingDuration}ms)
    

    It will render in a text log as something like this

    2018-08-16 13:44:27,617 [P25420/D2/T1] INFO  Umbraco.Core.PluginManager - Resolved umbraco.interfaces.IDiscoverable (took 352ms)
    

    However in addition in whatever datastore be it the additional JSON log file for example we will write to disk or store in a database I can get individual values out of the log message to search & query on.

    So for this example I could search for all log entries in the log where the TimingDuration property is greater than 400 milliseconds.

    If I was to do this with Log4Net I would only get the compiled message without the properties and I would have no simple way of searching through log entries unless you are a lover of a RegEx, which I am not :-P

    Let me know if this is still not clear and I will try my best to get my point across in a different way.

    Warren :)

  • Warren Buckley 2082 posts 4489 karma points MVP 6x admin hq c-trib
    Aug 17, 2018 @ 14:59
    Warren Buckley
    0

    Boo I don't know where my reply just went.. :(
    But to sum it up again briefly.

    Log4Net will store a rendered/compiled message, where Log4Net will store a message template along with properties.

    So each property in a log message can be searched on with Serilog, where you will have to be a guru with RegEx to search partial parts of a log message to try and find the same results.

  • Rick 92 posts 278 karma points
    Mar 12, 2019 @ 00:20
    Rick
    0

    Hi Jeffrey,

    As an aside to this (and related to this thread) ... I was at your CG '18 talk and I've followed your instructions as per your slide to configure log4net to the Windows Event Viewer and it doesn't work for me - I've followed your instructions to the letter...

    Any help appreciated.

    Thanks, Rick

  • Nicholas Westby 1876 posts 6250 karma points c-trib
    Aug 17, 2018 @ 16:01
    Nicholas Westby
    1

    Just poking my head in here because there was mention of storing logs to the database.

    In my experience, a large number of issues on Umbraco sites are due to database issues (e.g., database corruption, user changed, connectivity issue, etc.).

    I would not recommend storing logs to the database, as then we would be unable to see the errors when there is a database issue.

    Also, databases are more challenging to work with for some people. If there is a production outage, you don't want somebody who may not be as familiar with databases to have that as a barrier to figuring out the problem. A simple file on the file system makes it much easier to inspect the logs.

    You might say they can just look at the log viewer in the back office (should such a feature get built), but that would not be the case if the site is down.

    Of course, if you want to store both to the file system AND to the database, and a database outage would not prevent the file system log from working, then more power to you.

  • Warren Buckley 2082 posts 4489 karma points MVP 6x admin hq c-trib
    Aug 17, 2018 @ 17:41
    Warren Buckley
    0

    Hi Nicholas
    Thanks for your feedback. Yes storing to the database would be in addition to the two log files that we will output. A txt file as before and a JSON log file that contains all the extra properties and info.

    The only thing I would need to check is that if there is db errors or connectivity issues to the DB, that the text log files continue to output to disk all fine.

    The only thought about storing it in the DB is for a built in log viewer, as a central store of logs. Where reading log files from disk into memory and searching could be less performant along with trying to deal with log files from different servers in load balanced environments.

  • Heather Floyd 466 posts 583 karma points c-trib
    Mar 15, 2019 @ 19:10
    Heather Floyd
    0

    Hi Warren,

    I see that Umbraco 8 now includes Serilog as you suggested. I took a look at the documentation page, and installed Seq, but my question is this:

    If I have a local Umbraco 8 site running on IIS.... how do I get those logs to show up in the Seq interface?

    In Umbraco 7, I could just keep Notepad++ open on the log file, and pop over to read the latest messages easy-peasy. Now, though I see there is a json file in the folder... but it is really difficult to "read" when opened as a text file. I tried using JSON Buddy to view it in a more readable format, but it is not considered a valid JSON file, so it can't be parsed.

  • Sebastiaan Janssen 4811 posts 14059 karma points MVP admin hq
    Mar 16, 2019 @ 08:43
    Sebastiaan Janssen
    0

    Each line in the log is valid JSON though, but that is indeed annoying.

    Though Seq is cool, importing the data is an annoying command line thing and I didn't like it. Luckily Warren has been working on a tool to open Serilog log files in to make them easy to read, looks a lot like the viewer in the backoffice:

    https://www.microsoft.com/en-us/p/compact-log-viewer/9n8rv8lktxrj

  • Warren Buckley 2082 posts 4489 karma points MVP 6x admin hq c-trib
    Mar 16, 2019 @ 09:09
    Warren Buckley
    0

    Hi Heather,
    There are a couple of options:

    1. Use Compact Log Viewer on Windows Store that I uploaded
    2. Configure Serilog to Log into your local SEQ

    You can add Serilog.Sinks.Seq from Nuget and add this configuration to the serilog config files.

    <add key="serilog:using:Seq" value="Serilog.Sinks.Seq" />
    <add key="serilog:write-to:Seq.serverUrl" value="http://localhost:5341" />
    <add key="serilog:write-to:Seq.apiKey" value="[optional API key here]" />
    

    https://github.com/serilog/serilog-sinks-seq#xml-appsettings-configuration

    The last option is to configure Serilog to not write a JSON file but the TXT file that you prefer. Which the XML config files should give an example in the comments of the file on how to do it.

    Hopefully this helps.

    Warren :)

  • Heather Floyd 466 posts 583 karma points c-trib
    Mar 20, 2019 @ 16:01
    Heather Floyd
    1

    Thanks, guys!

    Warren - Nice job on the Windows desktop app, I've now installed it :-)

    Also, I appreciate the info about configuring a sink - I assume this is how one would configure a centralized logging scheme? If you had a Seq server somewhere you could have all your sites logging to that same server?

    Because I was having an installation error at the time of my post, I did need to read the log, and luckily I saw your commented example of enabling the TXT version int he config. That worked well in a pinch. Now that I have your nice tool (and I managed to get V8 installed correctly), I will switch it back to using the JSON format.

  • Warren Buckley 2082 posts 4489 karma points MVP 6x admin hq c-trib
    Mar 22, 2019 @ 09:34
    Warren Buckley
    0

    Yes Serilog uses the notion of Sinks, the community & Serilog themselves have written a ton of them to store logs in various formats and locations.

    Want it logged to a DB, Azure Application Insights, Elmah.io, the list is almost endless.

    But in regards to SEQ, you would have this installed & available on the internet somewhere so all your applications could log their messages into one central store for you to analyze & query.

    It all really depends on your needs and how you like to look, view & store logs.

  • Thomsen 73 posts 264 karma points
    Mar 22, 2019 @ 21:25
    Thomsen
    0

    Hi,

    Is there a build-in way in SeriLog, where you can get an object containing the current log list and iterate through it via LINQ? Let's say, I want to display the whole log on a viewpage for example, like it is displayed in the backoffice.

    Kind regards.

  • Sebastiaan Janssen 4811 posts 14059 karma points MVP admin hq
    Mar 23, 2019 @ 08:12
  • Thomsen 73 posts 264 karma points
    Mar 23, 2019 @ 11:18
    Thomsen
    0

    Nice - if nothing similar build in, that was what I was looking for. Thanks you!

  • Sebastiaan Janssen 4811 posts 14059 karma points MVP admin hq
    Mar 23, 2019 @ 13:58
    Sebastiaan Janssen
    0

    No problem, but I'm unsure what you're trying to do? You've seen the logviewer in the backoffice Settings section, right?

  • Thomsen 73 posts 264 karma points
    Mar 26, 2019 @ 10:18
    Thomsen
    0

    Yes - and the new backoffice log viewer works fantastic. I'm doing some dataimport frontend using ContentService and want to fetch the recent log after the import has finished, to show that the process has completed without errors. So I will adapt some of the logic from the JsonLogViewer.cs to do so.

  • Warren Buckley 2082 posts 4489 karma points MVP 6x admin hq c-trib
    Mar 27, 2019 @ 14:21
    Warren Buckley
    0

    @thomsen with Serilog you could create a new log file that only your custom application uses & display all messages from that log.

    Alternatively, you can add some specific property and search only for log messages where that property exists to filter out the logs from Umbraco itself.

  • Bo Damgaard Mortensen 709 posts 1175 karma points
    Apr 03, 2019 @ 21:39
    Bo Damgaard Mortensen
    0

    with Serilog you could create a new log file that only your custom application uses & display all messages from that log.

    Got any samples on how to do this? :-) Currently setting up a new project where I want logging from the codebase to be written to Azure Blob Storage rather than to Umbracos log.

    Thanks in advance :-)

  • Warren Buckley 2082 posts 4489 karma points MVP 6x admin hq c-trib
    Apr 12, 2019 @ 08:43
  • JuttaIrizarry 1 post 71 karma points
    Mar 26, 2019 @ 11:35
    JuttaIrizarry
    0

    On the off chance that logs are less requesting available than put everything at stake. can you furthermore have differing log levels for different get-togethers. https://arynews.tv/en/ That is directly possible with log4net. Likewise, I should need to have a log watcher in the backend. Directly we need to present diplo log watcher on all our non cloud adventures.

  • Warren Buckley 2082 posts 4489 karma points MVP 6x admin hq c-trib
    Mar 27, 2019 @ 14:23
    Warren Buckley
    0

    Hello Juttalirizarry

    I am not 100% sure I follow here and would recommend taking a read through some of Serilog documentation to see if it can help achieve what you want it to do.

Please Sign in or register to post replies

Write your reply to:

Draft