How to maintain unique log event identifiers

Logs have been around to troubleshoot issues in software systems since ever. They are a bottomless source of information on how things run under the surface. Logs contain a time stamp and a message at least, but more advanced cases imply other metadata associated with a log record. In this article I will focus on event IDs. Event IDs are a perfect way to distinguish events by types. It would make sense if all IDs were unique within the system being developed and if all IDs were bound to a specific code execution path. Now, lets see how we can have the event IDs unique.

Here is a code snippet:

logger.LogWarning(eventId, "Something funky happened, but we carry on");

This snippet belongs to a C# code file but something similar can be spotted anywhere. Here you see an expression that invokes a method on a logger object, and if you assume that this call ends up as a log entry of level “warning” somewhere in logs, you will be right and correct. What you don’t know for sure is what else this code shoves into a log entry. Actually it can take a lot of stuff from the context, i.e. server name, thread ID, user name, and any contextual information that was used to create the logger object, be it correlation ID or product area, etc. However it takes two arguments that it cannot infer from the context: eventId (which is an Int32) and the actual human readable message. This means you have to decide what value to use for the eventId.

The best decision you can face is the one you don’t need to make 😉

l5qxnmv
The hamster is happy to have unique event IDs

So here is the solution. I delegate the process of making this decision to a simple PowerShell script so you don’t have to. Here it is in full.

$files = gci . -Recurse -Filter *.cs | ? fullname -NotMatch "\\obj\\" | ? fullname -NotMatch "\\bin\\"
$presentIds = $files | %{ gc $_.FullName | sls -Pattern "\/\* eventid !(\d*)! \*\/"| % { [int]($_.Matches[0].Groups[1].Value) }}
$pointerId = ($presentIds | measure -Maximum | select -exp Maximum) + 1
$files | % { 
 $b=$pointerId; $f=$_
 $c=gc $f.FullName | % { 
  if($_.Contains("0x00")){
   $p = $pointerId++;$_.Replace("0x00","/* eventid !$($p)! */ $($p)") 
  } else { 
   $_ 
  } 
 }
 if($b -lt $pointerId){ 
  set-content -Path $f.FullName -Value $c
 }
}

Here are steps it performs:

  1. Get all files I am interested in (.cs files of my code base)
  2. Traverse though all of them to find what event IDs have been already used
  3. Pick an ID that has not been  used
  4. Traverse through files again and look for the placeholder and replace it with a new ID
  5. Optionally update the file contents if its contents must include new IDs

Here is how to use it.

When you write your code instead of picking an actual event ID set the value to 0x00. In C# 0x00 is the same as a good old zero and the code compiles perfectly fine. Just make sure you don’t use this fancy notation elsewhere for obvious reasons. Then run the script from the folder that contains your codebase and the placeholders will be replaced with non-zero integers.

This

logger.LogWarning(0x00, "Something funky happened, but we carry on");

becomes this

logger.LogWarning(/* eventid !15! */ 15, "Something funky happened, but we carry on");

I personally use the script to generate unique IDs for my log records that go to ElasticSearch. Then I use Kibana to build fashionable dashboards to track the health of my system.

You can take it further from there and set up alerting, i.e. for when an amount of dangerous events overflow a specific threshold your devops team gets a notification to dive in and investigate. Also it might prove reasonable to put this script as a pre-build step into your build server of you CI pipeline to never forget to run it manually.

P.S. I need to say that I love PowerShell most of all the shells I had my hands on. Its ability to operate on and pipe objects rather than plain stdin and stdout makes it by far superior. I strongly recommend it for automating any Windows based routines.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s