Collecting kernel events with NXLog for analysis in the Elastic stack

Let’s jump right into the example. Try running the following command as a superuser:

Substitute sda with an adequate disk available on your system. You’ll immediately see an avalanche of console output, followed by a summary report after about 3 seconds. Each line of output corresponds to a disk-related operation.

A brief explanation of the command line options used above:

Remember that blktrace does not generate any readable data, so its output is usually redirected to a file or — if you need real-time data collection — to a parsing program that can translate binary data into readable text. This is what -o- and -i- expressions are used for, and blkparse is the tool we need, which is usually bundled with the same OS package as blktrace.

Let’s see how we can interpret each line. This knowledge will help us further when we build our real-time analytics.

You can use a regular expression to parse the input data with NXLog Enterprise Edition. Alternatively, you can modify the default blkparse output to a different format, such as “key-value” pairs. This also gives you the ability to choose what data to log. For example, the following command assumes you’re not interested in the major-minor device identifiers, and that you would like to retrieve the number of bytes per operation instead of the default number of blocks:

The output will look like this:

Doesn’t that look much nicer than the default format?

Although configuring NXLog to process these logs is a simple task, there are some caveats that you should be aware of.

First, blkparse log lines only include the time of the event, not the date. This is a problem if you need to create reports spanning multiple days. The analytics platform needs both the date and time to make sense of the data. A simple workaround for this issue is to use NXLog’s built-in EventReveivedTime field. In most cases, the date that the event is processed is the same as the event date, so this is a safe assumption.

Second, running a kernel trace requires superuser permissions. By default, on Linux, the NXLog process runs with the dedicated nxlog user, which has fewer privileges as a best security practice. A possible workaround is to wrap our chained command into a script and declare blktrace as sudo-capable without asking for a password. To achieve this, add the following line in the /etc/sudoers file:

While it is not the best approach security-wise, it is sufficient for this demonstration.

Finally, use the following NXLog configuration to collect kernel events:

The following is an sample script that can be used with the im_exec input module:

Now it’s time to see our data in action with Elasticsearch and Kibana. We will not go into detailed installation instructions for these tools, but the following steps apply to most Linux distributions.

Open your Kibana instance for the first time by loading http://localhost:5601 from a local browser. The first time you access Kibana, you will be asked to add data by integrating with an external data provider or uploading a file.

Close this dialog and instead navigate to Management > Stack management > Index patterns. To avoid creating our index using the Elastic API, we can start NXLog at this stage to create our index automatically.

Start the NXLog service using your operating system’s service manager or use the following command:

This command starts NXLog in foreground mode and provides an explicit path to the configuration file we created above. As a result, you should instantly see the successful connection to your Elasticsearch instance, for example:

Refresh the Index Management page, and you should see the following screen:

Click Create Index pattern.

Enter the name of the index corresponding to the NXLog configuration. In this case, we use blk-test from our example above. Then, in the Timestamp field dropdown, select the EventTime field. Note that we do not have to instruct Elasticsearch on how to parse the timestamp field because we construct the expected date format by Elasticsearch in the NXLog configuration file.

Finally, you should see all the fields as follows:

Now go to Discover and verify that the data is present. Select Last 1 hour in the date range field, and you should see a nice histogram similar to the following:

You can also enable the auto-refresh feature to view updated data in real-time mode. Under Refresh every enter 5 seconds and click Start.

The graph will auto-scroll to the left when new data is displayed.

Finally, let’s create a practical real-time scenario for analyzing writing pressure on the disk.

Go to Visualize Library and filter out anything that is not related to writing operations by entering all types of RWBS fields that contain W (write):

Next, create an aggregation to visualize the total number of bytes grouped by application name:

You should see a graph similar to the following:

There is one caveat here; you probably expect to see recognizable application names, but you will notice that the list contains some unusual application names. If a process spawns a thread, the thread name will be listed instead of the program name itself. In the screenshot above, ThreadPoolForeg is a thread name belonging to Webkit-based web browsers like Opera and Chrome. Additionally, names like kworker/u8:2 or swapper/1 are kernel threads. In short, you may need to research which application each thread name belongs to.