TraceHub, a flexible solution for Web based structured logging

0
46

Introduction

TraceHub is a Web based centralized logging system that utilizes System.Diagnostic for structured logging, and SignalR for transporting structured traces from your service applications to trace observers. This open source project delivers 4 products out of the box:

  1. TraceHub MVC: ASP.NET MVC Application that provides the TraceHub service, displays structured traces from HubTraceListeners injected to your service applications, and push the traces to other clients like TraceHub Console.
  2. TraceHub Slim: Slim edition of TraceHub, with only 1 Web page and without built-in authentication, however with all key features of TraceHub MVC.
  3. TraceHub Console: Windows console application that listens to the TraceHub service and displays the traces.
  4. HubTraceListener: Derived class of System.Diagnostics.TraceListener, which uploads structured traces to the TraceHub service.

If you have been using Event Tracing for Windows (ETW) and trace listeners in System.Diagnostics or other tracing and logging frameworks compatible with System.Diagnostics, you may find that the learning curve of using TraceHub is almost zero, and your existing application codes don’t need to be altered for logging structured traces to the new medias, thus don’t need to be rebuilt.

And this article also introduces some design concepts / contexts behind TraceHub.

TraceHub MVC

TraceHub Console

TraceHub Slim

Use TraceHub

Presumably, you have been using Trace and TraceSource of System.Diagnostics in your applications, like these examples:

 try { ... Debug.WriteLine("..."); ... myTraceSource.TraceInformation("......"); ... myTraceSource.TraceEvent(TraceEventType.Warning, 3, "File {0} not found.", "test"); ... return true; } catch (IOException e) { Trace.TraceWarning(e.Message); return false; } catch (UnauthorizedAccessException e) { Trace.TraceWarning(e.Message); return false; } catch (System.Security.SecurityException e) { Trace.TraceWarning(e.Message); return false; } catch (FormatException ex) { System.Diagnostics.Trace.TraceWarning($"{s} is not a valid IP address or range."); return false; } catch (System.Exception ex) { Trace.TraceError(ex.ToString()); throw; } public class TraceErrorAttribute : HandleErrorAttribute { public override void OnException(ExceptionContext filterContext) { System.Diagnostics.Trace.TraceError("Controller: {0}; View: {1}; Exception: {2}", filterContext.Controller.ToString(), View, filterContext.Exception.ToString()); base.OnException(filterContext); } }

Step 1: Install TraceHub MVC or TraceHub Slim to a server

Simply download the source codes of TraceHub, build and deploy TraceHub MVC or  TraceHub Slim to a server as you would do for ASP.NET applications and configure the URL like http://mytracehub.com.

Remarks:

For TraceHub MVC, the Identity 2 database should have a user role named “API”, and a user associated with “API”. And you can may make TraceHub MVC share the same Identity 2 database with other ASP.NET MVC/Web API applications.

Step 2: Inject HubTraceListener to you application

Step 2.1: Copy the following files in the Fonlow.HubTraceListener CS project to the program directory

File List:

  • Fonlow.HubTraceListener.dll
  • Fonlow.TraceHub.Common
  • Essential.Diagnostics.Core.dll
  • Microsoft.AspNet.SignalR.Client.dll
  • Newtonsoft.Json.dll

Alternatively, you may import NuGet package Fonlow.HubTraceListener, even though your application codes don’t need references to those files.

Step 2.2: Modify app.config or Web.config of your application

Your service applications may be using Web.config or MyService.exe.config.

Example:

<system.diagnostics> <sharedListeners> <add name="hubListener" type="Fonlow.Diagnostics.HubTraceListener, Fonlow.HubTraceListener" template="{Message}{Data}" hubUrl="http://MyTraceHub.com" apiUser="api" apiPassword="MyPassword" instanceId="MyServiceInstanceId" /> <add name="rollingfile" type="Essential.Diagnostics.RollingFileTraceListener, Essential.Diagnostics" template="{LocalDateTime:HH':'mm':'ss} [{Thread}] {EventType} {Source}: {Message}{Data}"
        initializeData="%AllUsersProfile%\MyCompany\logs\MyService-{LocalDateTime:yyyy-MM-dd}-p{ProcessId}.log" /> </sharedListeners> <switches> <add name="TraceLevelSwitch" value="Verbose" /> </switches> <sources> <source name="myAppSource" switchValue="All"> <listeners> <clear /> <add name="hubListener" /> <add name="rollingfile" /> </listeners> </source> </sources> <trace autoflush="true"> <listeners> <clear /> <add name="hubListener" /> <add name="rollingfile" /> </listeners> </trace>
</system.diagnostics>

In this example, the template attribute for hubListener does not include time stamp and trace event type etc., however, TraceHub still display them. This is because HubTraceListener sends not only the formatted trace message according to the template, but also the structured trace data, so the TraceHub Web page would display them and filter them accordingly.
 

Hints:

For TraceHub Slim, the value of the apiUser attribute should be “anonymous”, and the value of password is not used.

Step 3: Up and Run

Both TraceListener and ASP.NET Web application are starting up in lazy manner. That is, only when the application or the CLR startup logic creates the first trace, the TraceListener instances defined in app.config are created; only when the first HTTP request reaches IIS, an instance of the Web application is created. And there could be significant interval between the first trace and the full operation of TraceHub, and there could be latency and interruptions between your application and TraceHub. HubTraceListener may buffer up to 100,000 traces in case of network outage between your applications and TraceHub. And it is good to keep a local rolling log files through RollingFileTraceListener, since local resources like local file and Windows Events log are the most reliable medias for logging.

Hints:

To minimize the negative impact of lazy loading, you may consider to alter the following setting:

  1. In Advanced Settings of the IIS Website, set “Start Automatically” or “Preload Enabled” to True.
  2. In the Advanced Settings of respective AppPool, set “Start Automatically” to True or set “Start Mode” to “AlwaysRunning”.
  3. In the Advanced Settings of respective AppPool, set “Idle Time-out(minutes)” to a larger number.

Architecture and Deployments

HubTraceListener listens to trace events of the service application, and upload the formatted trace message along with some structured trace info to TraceHub; and TraceHub pushes the trace data to Web browsers which are loading the Web pages of TraceHub MVC or TraceHub Slim, so you could view traces on the client side; and an alternative client viewer is TraceHub Console.

Deploy TraceHub components

If you want to introduce more trace sinks, you just inject respective trace listeners implemented in System.Diagnostics, Essential Diagnostics or Semantic Logging to TraceHub Console. You may install TraceHub Console in a Windows workstation or Windows Server, depending on how you would further process trace data.

To use products out of the box, you may download or clone the source codes of TraceHub, build and deploy, as describe in TraceHub Wiki.

Please note, applications that need HubTraceListener don’t need to be compiled with the listener, because derived classes of TraceListener could be injected to an application through app.config. And you just need to make sure the dependencies are available in the program directory.

 

Structured tracing and logging have been available since .NET Framework 2!

Over years, I have come across a few Web based logging and diagnostics tools for ASP.NET Web applications:

They are excellent tools, though I had rarely used them. And the scope of the TraceHub won’t be anywhere closer to Glimpse and Application Insights which cover wider spectrums and more scenarios.

If you have never used Serilog + Seq, you may probably skip this chapter and go next to “Design Concepts”.

A few months ago, I was introduced to  Serilog + Seq / Raygun in some Web service + Azure projects that I did not lead. So I had a bit hand-on experience in these new toys, while the team leads and other developers were eager to teach me the new concepts of structured logging. I was very puzzled, since I supposedly had been doing structured logging for years without these new toys or being aware of “structured logging”. And I had grown up in the .NET world since 2003 with these concepts:

  1. Use Trace and Debug of System.Diagnostics; and in complex applications and libraries, use TraceSource.
  2. .NET codes should have no knowledge of the logging mechanism. The logging is done through trace listeners, and trace listeners generally are injected by .NET runtime according to app settings in element system.diagnostics in app.config, so some CLR startup errors could be logged before the first line of the application code is executed.  
  3. System.Diagnostics since .NET Framework 2 had already provided advanced tracing of structured data and correlation.

With Serilog, you have to create an instance of LoggerConfiguration in your application codes and library codes, because CLR startup logic has no knowledge of it,

  1. So CLR startup errors won’t be picked up by Serilog.
  2. And every libraries you create will need to reference to Serilog just for the sake of logging. Why should I always reference to Serilog in every libraries? Not only 3rd party libraries, but also WCF, WPF and WF etc. had provided specific trace sources for diagnostics. Serilog and alike are missing these. A workaround is to use Serilog Tracelistener. But a logging instrument on top of another logging instrument is looking odd to me.

The popular Log4Net has similar shortfalls, even though if you have been using it since .NET Framework 1 you won’t see any problem.

A few weeks ago, I happened to have some moment reading the materials about Serilog and Seq in more details in addition to those in the official Websites:

It is confirmed that System.Diagnostics + Essential.Diagnostics had covered most of what Serilog offers. To be fair, Serilog does offer some additional sophisticated features:

  1. Message Template.
  2. Preserving Object Structure
  3. Flood gate upon identical traces in flooding

It is probably very context specific to value these features.

Structured tracing has been available in System.Diagnostics of .NET Framework since .NET 2 released in year 2005. And for structured logging, there are quite a few free and open source solutions around, and here’s an incomplete list:

Both Semantic Logging and Essential Diagnostics were designed on top of Event Tracing for Windows (ETW) and System.Diagnostics.

Design concepts for Web applications/services

When I lead a green field project, I would ensure:

  1. Small and evolvable designs.
  2. Basic separation of concerns;
  3. Conformation to SOLID; design patterns for right contexts.
  4. Component designs
  5. Separation of development concerns and deployment concerns; and application and library codes having least knowledge of the deployment environments.
  6. Defensive programming
  7. Static code analysis
  8. Integration tests as early as possible, in local dev machine first, then in the team test environment.
  9. Stress testing as early as possible

Also, I would:

  1. Avoid premature introduction of DI/IoC frameworks like Autofac and Unity etc.
  2. Avoid premature scalability with Microservices. 
  3. Avoid excessive trace and logging. Application codes should have no knowledge of the logging mechanisms, except System.Diagnostics. Trace listeners are generally injected by .NET runtime as defined in app.config.
  4. Except in small and simple business applications, do not mix technical logging and business activity monitoring as well as traffic monitoring.

For Web application and services, I would keep the VS projects of WCF, MVC and Web API as thin as possible. Web services, SOAP based or RESTful, are just a transportation layer or tier for delivering server side functions to clients and get feedback from clients. It is good for teamwork and testing to put most if not all the business logic into the model assemblies rather than in the Web entry assembly. And during stress testing of business domain functionality, I would already have good idea about the performances of the core business modules. If you take such approach, you will less likely have surprise about performance after deploying Web applications. If you endorse such design concepts, you may probably find TraceHub appealing.

Is Logging really important to SDLC?

While nowadays components of tracing and logging are fairly fast even in heavy traffic, however, excessive logging could hamper the efforts of debugging because the overwhelming info.

The bottom line is, if your program is highly reliable, you will depend less on logging; if you have good QA, your program will be naturally reliable and robust, and you will depend on less QC and testing; if you have good testing, you will depend less on debugging and logging. Debugging/diagnostic and logging should be the last resort to control quality. If your SDLC heavily depends on debugging/diagnostics and logging, there could be something dirty in your SDLC, eating you alive without you noticing it, even if you enjoy the technical challenges which bring no value to the stakeholders.

You may ask why I would develop something similar to Serilog + Seq etc., after saying all these. Here are my reasons:

  1. Logging and debugging are wastes that we developers haven’t managed to eliminate! However, we at least could make logging easier and cheaper for most scenarios of development and deployment on the ASP.NET stacks.
  2. System.Diagnostics since .NET 2 had already covered almost everything which Log4Net and alike cover. Some simple extensions like Essential.Diagnostics and Serilog are already well complementing what needed for distributed computing, while Essential.Diagnostics conforms more to  Event Tracing for Windows (ETW) and System.Diagnostics.
  3. Having structured logging and Web based logging together is much easier than you would had thought, as long as you pick the right resources to depend on. When using Serilog + Seq, I had already been feeling: logging shouldn’t be so complex, so hard, so slow, so unreliable and so expensive. Logging should be simple, fast, reliable and free, because (technical) logging is a waste in the first place.

Points of Interest

Over years I have been reviewing or maintaining quite a lot legacy applications with dirty designs and implementations, as well as excessive logging on variety of logging components. A few years ago I have done some extensive researches on logging components, before joining project Essential Diagnostic. I had been thinking of developing a light-weight centralized logging system occasionally over years. There have also been a few good Web based logging and diagnostics systems around like Glimpse and AI. Though they are comprehensive and heavy, there seemed no need for some additions to the landscape. The poor experiences in using Serilog+Seq had prompted me to develop a Web based centralized logging system based on System.Diagnostics + Essential Diagnostics + SignalR. To be fair, Serilog on its own is a well designed and implemented product, and is pretty fast. However, in my observations, people using Serilog had often enjoyed excessive logging and debugging on premature scalability with Microservices and premature usage of CI server like TeamCity, rather than spent more efforts in making simpler designs and writing clean codes. So I was thinking whether a light-weight Web based logging system could be fixing the gap between primitive log files and heavy tools like Glimpse and AI, and providing a free, simpler and more flexible alternative to Seq. Here you are, when you have some light-weight needs for Web based centralized logging as I normally do, you will have more choices for your contexts.

Do you find it interesting that the author of the logging components does not encourage developers to log and debug?

What’s Not

TraceHub is designed to be a light-weight centralized logging service extending what already in System.Diagnostics and Essential.Diagnostics. While it has some some overlap with Glimpse, Microsoft Application Insights and Azure Event Hubs, it won’t be extended to the wider spectrums of these products.

Differences from Seq

Seq stores traces, while TraceHub does not store traces directly. If you want to persist traces, there exist trace listeners to be injected to TraceHub Console that could be running on the server side.

Other than this, TraceHub has covered most functionality of Seq, additionally, it is free, fast, open source and more flexible.

Differences from Serilog

Serilog is apparently to become a better log4net, while HubTraceListener is based on System.Diagnostics and Essential.Diagnostics, inheriting the capability of structured logging. Serilog endorses some fluent API coding style, Most of the differences had already been mentioned in this article about the design concepts and contexts in SDLC.

Tracing, Logging, Business Activity Monitoring

The creator of Essential Diagnostics Sly Gryphon said: ” A distinction should be made between the concepts of logging and tracing (although sometimes the terminology used is unclear). “. In my view, generally you decide what to trace during development/coding, and decide whether to log, what to log and where to log during deployment and operations.

Business Activity Monitoring (BAM) is software that aids in monitoring of business activities implemented in computer systems. So BAM is application specific, and it is natural that BAM is tightly associated with your applications codes, while the concrete implementation of logging like trace listeners should be de-coupled from your applications codes, and it is even better that your applications codes have no knowledge of logging until deployment and operation. In small and simple applications, you may probably use tracing (with Trace, TraceSource, Log4Net, or Serilog) and logging (with trace listeners) to implement BAM. However, for more complex applications, it is better to separate technical logging and BAM, and develop or use a dedicated subsystem like Biztalk BAM to monitor business activities.

A few years ago I had maintained some legacy Biztalk applications designed and implemented by a consultant firm, and previous developers had used Biztalk BAM to log all kinds of technical traces and very little business activities. It is not hard to imagine the impacts on development and operations from such design, even if you haven’t ever used Biztalk BAM.

There’s no one-size-fits-all. It is quite fine that your ASP.NET projects use Glimpse, AI, TraceHub and Azure Event Hubs for different concerns and contexts in order to scale and evolve.

Further References

LEAVE A REPLY