Last updated at Mon, 06 Nov 2017 20:38:38 GMT

In my previous article, How to Ensure Self-Describing Log Data using Log4Net, I showed you a  technique that made structuring your logging information as key-value and JSON under Log4Net an easier undertaking. In this article I am going to apply the same concepts to NodeJS. I’ll show you how to make it so that so you can ensure logging uniformity among all the NodeJS developers in your enterprise with little to no additional effort. In this article I am going to focus on using JSON as the self-describing data format. I find it to be a format that provides a lot of structure but also a lot of flexibility. And, Logentries has intelligence built into the way it consumes JSON that makes for a compelling use case.

The Benefit of Self-Describing Data Structures

Before we get into the details of using JSON with NodeJS and Logentries, let’s take a fast review of the benefits of the using self-describing data formats when logging. Consider the following log entries in Listing 1, below.

» 12 May 2016 09:42:58.390 info GET call. All is well.
» 12 May 2016 09:42:58.558 { "application": "resel-logger demo", "details": { "path": "/", "method": "GET", "type": "API", "comment": "All is well." }, "level": "info"}

Listing 1: Self-describing data formats are easier to index and easier to use

Notice the first entry. It tells us nothing more than a log entry of level info was made at a certain time. Also, there is some message text about making a GET call. You really have no idea what the information is about or where it came from.

The second entry tells us a lot more. You know the application that made the entry. Also you know there are details and that the details are segmented by the properties, path, method, type and comment. How do we know all these things? Because the second entry is in a self-describing data format, in this case JSON.

The first entry leaves a lot to be figured out. The second entry lays it all out for you. And, not only is the second entry easy for a human to understand, the JSON can be parsed and indexed automatically in a logging platform such as Logentries. Self-describing data formats are easy for humans and they are easy for machines. It’s a win-win situation.

Who is the intended reader of this article?

I assume that the reader of this article is an enterprise level software developer who is coding in NodeJS using Javascript. Thus, I assume that you understand the fundamentals of using Javascript objects.

Creating Self-Describing Log Entries Using JSON

So, how do we make is it so that your team is logging using a structured data format such as JSON? In the previous article I showed you how to use a technique that uses a C# object within an application to define a common data structure. Then, you attach relevant information to the properties of the C# object, convert that object to a JSON string and emit the JSON out as log submission.

We can apply  to NodeJS this idea of using an object to structure log data. Consider please the code in Listing 2 below:

Listing 2: Structuring your data using a Javascript object has many advantages

The code in Listing 2 above is an example of how a Javascript object can be used for structuring log data. Listing 2 is the log entry made within the onListening() event handler for a NodeJS application I am writing. I submitted the entry using the Logentries NodeJS Agent.

Listing 3 below is a code snippet that shows the onListening() behavior upon startup.

Listing 3: Logentries accepts a Javascript object when logging

Notice please that in Listing 3 above I have an object, loggingUtils that publishes as property, loggingObject. The object, loggingUtils is a custom object I made. You <a href="http://stackoverflow.com/questions/1646698/what-is-the-new-keyword-in-javascript">new</a> the property, loggingObject to a Javascript object that has structure shown in Listing 4, below:
application:'resel-logger demo', created:'2016-05-12T16:44:55.151Z', details:{},<br></br> }
**Listing 4: ****loggingUtils.loggingObject is **a custom logging object provides the skeleton logging structure and essential data you want to log .

The loggingObject provides the base structure and information I want to log. I new an instance of the loggingObject and then I create, on the fly, an object variable o that contains a property, event and a property, message. I assign data to the properties of o. Finally I assign the object variable, o to loggingObject.details (loggingObject.details = o), which I log.

Why are you newing loggingUtils.loggingObject?

The reason that I am using new to create a loggingUtils.loggingObject is because I need to create a distinct instance of the loggingUtils.loggingObject and in turn have its constructor behavior invoked. loggingUtils.loggingObject has a property, created which indicates the datetime when the object was created. The property, created is initialized as part of the object construction, like so.

In reality loggingUtils.loggingObject is a class. I new loggingUtils.loggingObject to create an instance of class and implicitly call the object’s constructor which initializes loggingUtils.loggingObject.created with the immediate datetime.

Listing 5 below shows how Logentries displays that logged JSON in Log View. Figure 1 below shows how Logentries displays the logged entry in Table View. Notice please that the log submission is segmented and indexed according to the structure of the JSON logged.

May 2016 10:38:12.460 { "application": "resel-logger demo", "created": "2016-05-12T17:38:12.523Z", "details": { "event": "onListening", "message": "Listening on port 3000" }, "level": "info" }

Listing 5: Logentries accepts JSON as a standard log entry

Figure 1: Logentries has intelligence to automatically segment and index JSON according to the structure of the submitted object

The important thing to understand here that at no time did I log using a level declaration, info for example,  and some explanatory message string. Instead, I structured my log information using a Javascript object and I logged that object. In this case, I logged the Javascript object using the Logentries NodeJS Agent in order to take advantage of the automated capabilities the agent provides. However, were I in another environment, I could log the information expressed as a Javascript object by converting the object to JSON by using a JSON.stringify call like so:

JSON.stringify(loggingObject);

Again, the important thing is that I am logging information in a structured, self-describing format.

Where does “level”:”info” come from?

When you take a look at the JSON that eventually shows up in the Logentries Log (Listing 5) and Table Views (Figure 1), you will see a that the property, level is part of the JSON that has been logged. When you look over the code that I’ve done, you’ll notice that I did not add “level”: “info” to the JSON. However, I did submit my original JSON using log.info(MY_JSON_OBJECT). So, how did the property, level get injected into my JSON? Logentries Agent did for free!

Logentries has intelligence that will include the level being logged right into the JSON entry.

Nesting a Variety of JSON Objects

Depending on the event or situation I want to log, I can extend the use of my loggingObject by assigning more in-depth JSON to the property, details of the loggingObject.  Listing 6 below shows how I report requests to an API endpoint by assigning a custom Javascript object to the property, details of my base loggingObject. The application and created information is built into loggingObject, so I don’t have to trouble myself with it. Instead, I can focus on adding the data I want to the property, details.

Listing 6: You can create custom Javascript object within a predefined logging object to provide flexibility for logging data in a self-describing manner.

The result of the log entry is shown below in Listing 7.

12 May 2016 11:29:58.761 { "application": "resel-logger demo", "created": "2016-05-12T18:29:27.132Z", "details": { "path": "/", "method": "GET", "type": "API", "comment": "All is well." }, "level": "info", "_level": "info" }

Listing 7: Logentries allows your NodeJS application to log nested JSON that will be segmented and indexed automatically.

Figure 2 below shows how different JSON structures get displayed in Logentries. If a property has JSON as an assigned value, that JSON gets segmented according to the property.

Figure 2: Logentries accommodates displaying a variety of JSON structures in a single, logical view

Using a Javascript object is both a structured and flexible way to create log data.

Putting It All Together

There are many benefits to logging using a self-describing data format such as JSON. Not only can you have an immediate understanding about the nature and use of the data being logged, you can enjoy the segmenting and indexing automation that a collection tool such as Logentries provides. Also, using a structured, self-describing data format enforces a certain degree of discipline within the coding team in a way that is easy to follow. Of course, there is always a risk that a developer will create a data structure that is particular to his or her need. However, the versatility that a collector such Logentries provides means that special data can be accommodated just as easily as data that conforms to company’s standard and convention, provided that the special data being submitted is in a self-describing format such as JSON. Self-description make life easier for both man, machine and the use cases that need to be supported well after the log entry is made. And, if you use a tool such as Logentries to consume your self-describing data, when the time comes to query your logs, you’ll enjoy the benefit of the automation that is provided in terms of segmenting and indexing the information.

Getting the Code

You can find the code for this article in the project, node-logging-demo, on GitHub, here.