JLogger6 - When You Care to Write the Very Best

Introduction

JLogger6 is a singleton component as a .NET 6 library component that can be used with any .NET project that supports .NET 6.

• The NuGet component is found by searching NuGet for Jeff.Jones.JLogger, or by going directly to https://www.nuget.org/packages/Jeff.Jones.JLogger6/6.0.1.
• The source code for the NuGet package is found at https://github.com/MSBassSinger/JLogger6.
• The code for the demo discussed in this article is found at https://github.com/MSBassSinger/LoggingDemo6.

JLogger has these characteristics:

• Multithreaded use – As a singleton, it is accessible from any thread, and uses locking techniques to ensure there are no collisions.
• High throughput – If the log is being used by many threads concurrently, the log writes do not stop the calling thread. JLogger uses a first-in, first-out (FIFO) queue where log writes are put in a queue and written to a file in a separate thread, concurrently in the background. The WriteDebugLog command takes the parameters, creates the log data, puts it in a queue. None of those steps are blocking.
• Send an Email – A debug log write can optionally send an email (SMTP configuration data required)
• Multiple Log Entry Types – There are several log entry types to choose from. What each of them means is up to the user writing the code. Some log types are reserved for the component, and would be ignored in processing the log entry. These are detailed below.
• New Log File each Day – After midnight, a new log file is created so log files are named to show the date and time span the log was active.
• Log Retention – Logs are automatically removed after the specified number of days, unless zero is specified, in which case no log files are deleted.
• Tab-delimited Log File – The log is written as a tab-delimited file. This enables opening up the file in programs like Excel for analysis.
• Optionally write the log to a database - When the user prefers having the log written to a database, this option is available for SQL Server. Scripts are provided to create the DBLog table and the stored procedures used to insert a log record and to perform log retention on the records.
• Optionally store log files in Azure File Storage - By specifying the Azure storage, when the log closes, the log file is copied there and deleted locally.

Logging Made Simple

I have tried several logging packages over the years. Some of them are excellent, most are useful in some scenarios. I do not intend to disparage any of them. You may find other packages work better for what you want. As I describe the use of this NuGet package in the demo app, you may find the simplicity, versatility, scalability, and performance something you want.

Setting up the Logger

One of the key items in the logger is the LOG_TYPE Enumeration. This provides a way to specify what type of log entry the entry is, and an easy way from the calling code to choose whether to make a log entry or not. This allows runtime changing of what is logged and what is not. This will become apparent in the later sections.

These lines of code are used to illustrate the use of JLogger. There are more
variations than documentation can show, but this shows a fully functioning use
of JLogger.

First, the usings that reference the libraries:

using Jeff.Jones.JLogger6;
using Jeff.Jones.JHelpers6;

Below is an example of setting a class-wide variable for the debug log options you want enabled. What you set may be different for development, QA, production, and troubleshooting production.

This global value for the program is usually stored in some configuration data location.

LOG_TYPE m_DebugLogOptions = LOG_TYPE.Error | LOG_TYPE.Informational |
                             LOG_TYPE.ShowTimeOnly | LOG_TYPE.Warning |
                             LOG_TYPE.HideThreadID | 
                             LOG_TYPE.ShowModuleMethodAndLineNumber |
                             LOG_TYPE.System | LOG_TYPE.SendEmail;

The next step is setting variables used to configure the Logger, typically in the programs startup code, as early as possible, before the logger is needed.

Boolean response = false;
String filePath = CommonHelpers.CurDir + @"\";
String fileNamePrefix = "MyLog";

// This value applies to both debug files and to DB log entries.
Int32 daysToRetainLogs = 30;

// Setting the Logger data so it knows how to build a log file, and
// how long to keep them. The initial debug log options is set here,
// and can be changed programmatically at anytime in the
// Logger.Instance.DebugLogOptions property.
response = Logger.Instance.SetLogData
           (filePath, fileNamePrefix, daysToRetainLogs, logOptions, "");

If using a database to store logs, then use this code as an example instead of the preceding.
Note: You can set this with "useDBLogging = false", and it will use a file as specified in the SetLogData method above.

These lines show how to setup the DB-based logging. The T-SQL script for the DBLog table and the two stored procedures must be executed on the database where you want the log entries.

If using Windows Authentication for access to your DB, make sure the windows account has the necessary permissions on SQL Server, and you can leave the DBUserName and DBPassword as "". The internal database connection constructs the correct connection string from the values passed in with SetDBConfiguration().

Boolean response = false;
String serverInstanceName = "MyComputer.SQL2020";
String dbUserName = "";
String dbPassword = "";
Boolean useWindowsAuthentication = true;
Boolean useDBLogging = true;
String databaseName = "myData";

response = Logger.Instance.SetDBConfiguration(serverInstanceName,
                                              dbUserName,
                                              dbPassword,
                                              useWindowsAuthentication,
                                              useDBLogging,
                                              databaseName);

Three database scripts are provided, and must be run on the target SQL Server.

• DBLog.sql - Creates the DBLog table and the primary key index.
• spDebugLogDelete.sql - Deletes records older than a certain date. See the DataAccessLayer.ProcessLogRetention() method for its use.
• spDebugLogInsert.sql - Inserts log records. See the DataAccessLayer.WriteDBLog() method for its use.

If logging to a file, and you want to use Azure File Storage, you will need to add this configuration. The log file is used locally while open for performance reasons (writing one line at a time across the network to an Azure file would be much slower due to network overhead). When the log is closed, the log file is copied to the Azure File Storage that is specified. Log retention is run on Azure File Storage, instead of locally, as the local log file is deleted after being copied to Azure File Storage.

// Optional configuration for Azure file storage
String resourceID = "<AZURE_CONNECTION_STRING>";
String fileShareName = "<AZURE_FILE_SHARE_NAME>";
String directoryName = "<AZURE_DIRECTORY_NAME>";
response = Logger.Instance.SetAzureConfiguration
           (resourceID, fileShareName, directoryName, true);

One of the options, regardless of the location of the logs, is to send emails. This is the configuration to enable the use of emails for log entries that specify it. Enabling alone does not send emails. More about that in the code section below:

// Email setup.
// Note that the Debug Log Options must have the LOG_TYPES.SendEmail flag in order for a 
// given log entry to send an email.  
// If that flag is not in the log options bitset, then adding to the flags for a 
// log entry will not send email.  Both must be present in the log options and the 
// log entry for the email to be sent.
Int32 smtpPort = 587;  // Or whatever port your email server uses.
Boolean useSSL = true;

List<String\ sendToAddresses = new List<String>();
sendToAddresses.Add("MyBuddy@somewhere.net");
sendToAddresses.Add("John.Smith@anywhere.net");

response = Logger.Instance.SetEmailData("smtp.mymailserver.net",
                                        "logonEmailAddress@work.net",
                                        "logonEmailPassword",
                                        smtpPort,
                                        sendToAddresses,
                                        "emailFromAddress@work.net",
                                        "emailReplyToAddress@work.net",
                                        useSSL);

// This is an example of how to use the LOG_TYPES.SendMail flag when writing to the log
// so that an email is sent.
if ((m_DebugLogOptions & LOG_TYPES.Error) == LOG_TYPES.Error)
{
   Logger.Instance.WriteDebugLog(LOG_TYPES.Error & LOG_TYPES.SendEmail,
                                 exUnhandled,
                                "Optional Specific message if desired");
}

and the same log entry if sending an email is not wanted:

if ((m_DebugLogOptions & LOG_TYPES.Error) == LOG_TYPES.Error)
{
   Logger.Instance.WriteDebugLog(LOG_TYPES.Error,
             exUnhandled,
             "Optional Specific message if desired");
}

Configuration need only be done once. However, in keeping with the goal of being dynamic, the Logger.DebugLogOptions property can be set at runtime to whatever bitset is desired. For example, if you want to increase logging without restarting a system, simply update the debug log option value in a config file to turn on more logging bits, and have whatever process monitors the config file update the Logger.DebugLogOptions property. Now more things will be logged, and you can decrease the amount of logging back to normal levels for what you want.

Logging Example in Code

One performance thing to note is the bitset comparison before calling a logging method. If the bit is not turned on, the code to log something is not executed. Thus, performance is not affected by adding more log entries unless they are used. So things like performance and flow can be coded, but unless turned on, would not affect performance. This approach allows a lot of versatility to be designed into the code for debugging and analysis without affecting performance.

// Example of use in a method
void SomeMethod()
{
  // Use of the Flow LOG_TYPE shows in the log when a method was entered,
  // and exited. Useful for debugging, QA, and development. The Flow bit
  // mask is usually turned off in production to reduce log size.
  if ((m_DebugLogOptions & LOG_TYPE.Flow) == LOG_EXCEPTION_TYPE.Flow)
  {
    Logger.Instance.WriteToDebugLog(LOG_TYPE.Flow, "1st line in method", "");
  }
  // This variable notes when the method started.
  DateTime methodStart = DateTime.Now;
  try
  {
    // Do some work here
    // This is an example of logging used during
    // process flow. The bitmask used here does not
    // have to be "Informational", and may be turned
    // off in production.
    Logger.Instance.WriteToDebugLog(LOG_TYPE.Informational,
                                    "Primary message",
                                    "Optional detail message");
    // Do some more work
  }
  catch (Exception exUnhandled)
  {
    // Capture some runtime data that may be useful in debugging.
    exUnhandled.Data.Add("SomeName", "SomeValue");
    if ((m_DebugLogOptions & LOG_TYPE.Error) == LOG_TYPE.Error)
    {
      Logger.Instance.WriteToDebugLog(LOG_TYPE.Error,
                                      exUnhandled,
                                      "Optional detail message");
    }
  }
  finally
  {
    if ((m_DebugLogOptions & LOG_TYPE.Performance) == LOG_TYPE.Performance)
    {
      TimeSpan elapsedTime = DateTime.Now - methodStart;
      Logger.Instance.WriteToDebugLog(LOG_TYPE.Performance,
                                      String.Format("END; 
                                      elapsed time = [{0:mm} mins, 
                                      {0:ss} secs, {0:fff} msecs].", objElapsedTime));
    }
    // Capture the flow for exiting the method.
    if ((m_DebugLogOptions & LOG_TYPE.Flow) == LOG_EXCEPTION_TYPE.Flow)
    {
      Logger.Instance.WriteToDebugLog(LOG_TYPE.Flow, "Exiting method", "");
    }
  }
} // END of method 

Much of the use of the logging code can be copy-and-paste, reducing development time.

The ILogger Option

In order to use JLogger6 in .NET applications that utilize the ILogger interface, simply get a reference to the ILogger interface of the Logger.Instance object.

LogLevel translations to JLogger6 log types:

• LogLevel.Critical adds LOG_TYPE.Fatal to the debug log options
• LogLevel.Debug adds LOG_TYPE.System to the debug log options
• LogLevel.Error adds LOG_TYPE.Error to the debug log options
• LogLevel.Information adds LOG_TYPE.Informational to the debug log options
• LogLevel.Warning adds LOG_TYPE.Warning to the debug log options
• LogLevel.Trace adds LOG_TYPE.Flow to the debug log options

These are the ILogger methods and how they use the underlying Logger instance.

void Log<TState>(LogLevel logLevel, EventId eventId, 
     TState state, Exception exception, Func<TState, Exception, string> formatter)

Writes to the log as:

WriteDebugLog(logType, exception, $"EventID = {eventId.ToString()}; 
              State = {state.ToString()}");

bool IsEnabled(LogLevel logLevel)

Checks the debug log option bitset to see if the translated bit is enabled or not.

IDisposable BeginScope<TState>(TState state)

Starts the log and returns an IDisposable reference to the Logger.Instance object.

Let's Look at the Log

This is a sample of the first few lines. When the log starts, the Logger automatically takes a snapshot of a number of system values that have proven to be useful in diagnostics and analysis later.

The columns are:

1. Time (or Date/Time, depending on the LOG_TYPE flag, ShowTimeOnly). This provides the time down to the millisecond. Normally, a log closes at midnight and a new one is started, so the ShowTimeOnly flag is commonly used.
2. Log Type - The log type of the entry (the name of the LOG_TYPE value used with the log entry)
3. Message - The primary message of the log entry
4. Addt'l Info - Additional, usually more detailed, information that explains the Message.
5. Exception Data - The name-value pairs of an exceptions Data collection. Using this Exception class feature wisely can be crucial to saving time in troubleshooting and diagnosis.
6. Stack Info - Stack information from the exception instance
7. Module - The name of the module where the log entry occurred
8. Method - The name of the method where the log entry occurred
9. Line No. - The line number where the error occurred
10. Thread ID - The .NET thread ID, if provided

The log file can also be opened directly in Excel (or any spreadsheet that interprets tab delimited columns). Excel allows for more intricate searching and analysis than a text editor like Notepad.

If a log file or log database table cannot be written to, the Logger creates an "Emergency Log File", also tab delimited. It is written directly (instead of via a queue) and provides basic information.

One way or another, the Logger tries to make sure a log entry is written.

A Look at the Demo App

The demo program is a .NET 6 Windows Forms application. Unlike a normal implementation of the Logger, the Logger is actually configured, run, and shutdown in the code called by the Run Test button. The purpose of this demo is to show how the Logger is used in various configurations.

The code can be download from https://github.com/MSBassSinger/LoggingDemo6 so you can step through it and test it as you want.

Coming Attractions

I am working on the next version to support user defined fields in the file log and the database. The concept is to allow the user defined fields to be defined and/or created when the log is configured, and as such, they could change for any given application over time.

In addition, I am working on an option for database log storage to add an audit table such that records deleted from the DBLog table are noted in the DBLogAudit table. This option may be needed for those who must preserve log records and actions taken on log records.

Conclusion

I wanted to create a logger that has a simpler, consistent setup and use. I wanted to provide for a wide range of log types without having to go back and recode, so turning bits on and off satisfies that. And I wanted the logger to handle multiple threads and tasks with a high throughput of log entries without affecting performance.

Dependency Injection (DI) purists may be averse to the use of a singleton. However, DI is a design concept meant to apply to objects created within another object that affect the business rules. In the case of a logger, it is not created within the object and it does not affect the business rules. So the use of a singleton logger does not violate the original purposes of DI. Just as an object may be dependency injected via constructor, method, or property, it is just as valid to introduce the outside object (the Logger instance) as a singleton. In all three cases, a reference to the Logger instance is injected (pushed or pulled) and not created.

Some developers already have a favorite logger. Others just take what is easiest with the least work. But if you are open to seeing if there is value in JLogger6, and want to get the most out of logging, I hope you will give this logger a good shot.

Background

I have been developing software on multiple operating systems and in multiple languages for over 40 years. Long before Windows. Long before Linux. One of the several consistencies in logging has been the need for logging in order to gauge performance. record errors, warnings, and other information, all of which make the job of solving production, QA, and development application problems less painful. I wrote this component so I can use logging in just about any scenario, configured for just what I need, that does not slow down the application execution.

Using the Demo Code

Pull the demo project from the GitHub repository. The code is well-commented and shows how to configure and use JLogger6. The demo was written in C# in Visual Studio 2022. The demo code is targeted to .NET 6. JLogger6 is targeted to .NET 6.

Points of Interest

I wanted to create a logging component that was easy to use, easy to setup, and using bit comparisons, would skip the method call to the log when not needed. I decide to use a queuing approach to log file writing when I ran into a case where hundreds to thousands of tasks/threads were trying to write to the log file. It slowed the UI down a lot. Changing to that architecture eliminated the issue.

History