Log Everything as JSON

Logging and monitoring are like Tony Stark and his Iron Man suit, the two will go together. Similarly, logging and monitoring work best together because they complement each other well.

For many years, logs have been an essential part of troubleshooting application and infrastructure performance. But over the period of time we have realized that logs are not only meant for troubleshooting purposes, they can also be used for business dashboards visualization and performance analysis.

So logging application data in a file is great, but we need more.

Why JSON logging is best framework?

For understanding the greatness of the JSON logging framework, let’s understand this conversation between Anuj(A system Engineer) and Kartik(A Business Analyst).


A few days later Kartik complains that Web Interface is broken. Anuj scratches his head and takes a look at the logs and realizes that Developer has added an extra field to the log lines broked his custom parser.

I am sure anyone can face a similar kind of situation.

In this case, if Developer has designed the application to write logs as JSON, it would be a piece of cake for Anuj to create a parser for that because then he has to search fields on the basis of the JSON key and it doesn’t matter how many new fields are getting added in the logline.

The biggest benefit of logging in JSON is that it has a structured format. This makes possible to analyze application logs just like Big Data. It’s not just readable, but a database that can be queried for each and every field. Also, every programming language can parse it.

Magic with JSON logging

Recently, we have created a sample Golang application to get Code Build, Code Test and Deployment phase experience with Golang Applications. So while writing this application we have incorporated the functionality to write logs in JSON.
The sample logs are something like this:-

And while integrating ELK for logs analysis, the only parsing line we have to add in logstash is:-

 
filter {
    json {
        source => "message"
    }
}

After this, we don’t require any further parsing and we can add as many fields in the log file.

As you can see I have all fields available in Kibana like:- employee name, employee city and for this, we do not have to add some complex parsing in logstash or in any other tool. Also, I can create a beautiful Business Dashboard with this data.

Application Repository Link:-
https://github.com/opstree/Opstree-Go-WebApp

Conclusion

It will not take too long to migrate from text logging to JSON logging as there are multiple programming language log drivers are available. I am sure JSON logging will provide more flexibility to your current logging system.
If your organization is using any Log Management platform like Splunk, ELK, etc. I think JSON logging could be a companion of it.

Some of the popular logging drivers which support JSON output are:-

Golang:- https://github.com/sirupsen/logrus
Python:- https://github.com/thangbn/json-logging-python
Java:- https://howtodoinjava.com/log4j2/log4j-2-json-configuration-example/
PHP:- https://github.com/nekonomokochan/php-json-logger

I hope now we have a good understanding of JSON logging. So now it’s time to choose your logging wisely.


That’s all I have, thanks for reading, I’d really appreciate any and all feedback, please leave your comment below if you guys have any feedback or any queries.

Cheers till next time!!

Image Reference:- https://www.google.com/url?sa=i&source=images&cd=&cad=rja&uact=8&ved=2ahUKEwi0jJzD8t_mAhVOzDgGHc6ODNQQjB16BAgBEAM&url=https%3A%2F%2Fwww.youtube.com%2Fwatch%3Fv%3DbPTZ43nM688&psig=AOvVaw0N3k7-bSq4OD4oMxPxYPrN&ust=1577881894317756

Logstash Timestamp

Introduction

A few days back I encountered with a simple but painful issue. I am using ELK to parse my application logs  and generate some meaningful views. Here I met with an issue which is, logstash inserts my logs into elasticsearch as per the current timestamp, instead of the actual time of log generation.
This creates a mess to generate graphs with correct time value on Kibana.
So I had a dig around this and found a way to overcome this concern. I made some changes in my logstash configuration to replace default time-stamp of logstash with the actual timestamp of my logs.

Logstash Filter

Add following piece of code in your  filter plugin section of logstash’s configuration file, and it will make logstash to insert logs into elasticsearch with the actual timestamp of your logs, besides the timestamp of logstash (current timestamp).
 
date {
  locale => "en"
  timezone => "GMT"
  match => [ "timestamp", "yyyy-mm-dd HH:mm:ss +0000" ]
}
In my case, the timezone was GMT  for my logs. You need to change these entries  “yyyy-mm-dd HH:mm:ss +0000”  with the corresponding to the regex for actual timestamp of your logs.

Description

Date plugin will override the logstash’s timestamp with the timestamp of your logs. Now you can easily adjust timezone in kibana and it will show your logs on correct time.
(Note: Kibana adjust UTC time with you bowser’s timezone)

Snoopy + ELK : Exhibit sudo commands in Kibana Dashboard

Logging User Commands: Snoopy Logger

About Snoopy Logger

Snoopy logs all the commands that are ran by any user to a log file. This is helpful for auditing and keep an eye on user activities.

Automated Installation

For Automated Installation/Configuration of Snoopy we have created a Puppet module and Ansible Role.

Manual Installation

To install the latest STABLE version of Snoopy, use these commands:
rm -f snoopy-install.sh
wget -O snoopy-install.sh https://github.com/a2o/snoopy/raw/install/doc/install/bin/snoopy-install.sh
chmod 755 snoopy-install.sh
./snoopy-install.sh stable

Output

This is what typical Snoopy output looks like:
2015-02-11T19:05:10+00:00 labrat-1 snoopy[896]: [uid:0 sid:11679 tty:/dev/pts/2 cwd:/root filename:/usr/bin/cat]: cat /etc/fstab.BAK
2015-02-11T19:05:15+00:00 labrat-1 snoopy[896]: [uid:0 sid:11679 tty:/dev/pts/2 cwd:/root filename:/usr/bin/rm]: rm -f /etc/fstab.BAK
These are default output locations on various Linux distributions:

  • CentOS: /var/log/secure
  • Debian: /var/log/auth.log
  • Ubuntu: /var/log/auth.log
  • others: /var/log/messages (potentially, not necessarily)

For actual output destination check your syslog configuration.
Snoopy provides a configuration file “/etc/snoopy.ini” where you can configure snoopy to generate logs. By default snoopy logs only uid, but doesn’t logs username in logs, so we have to change configuration to get username in logs.You may also specify the log path where you want to generate the snoopy logs.
For getting username in logs edit “/etc/snoopy.ini” and under [snoopy] section add the following line:
message_format = “[username:%{username} uid:%{uid} sid:%{sid} tty:%{tty} cwd:%{cwd} filename:%{filename}]: %{cmdline}”
The output of logs is  shown below:
Feb 25 07:47:27 vagrant-ubuntu-trusty-64 snoopy[3163]: [username:root uid:0 sid:1828 tty:/dev/pts/0 cwd:/root filename:/usr/bin/vim]: vim /etc/snoopy.ini

Enable/Disable Snoopy

To enable snoopy, issue the following command:
snoopy-enable
To disable snoopy, issue the following command:
snoopy-disable

Using ELK to parse logs

Now that we have logs with suitable information we will write a grok pattern in logstash to parse these logs and generate required fields.
A sample grok pattern will be like this:


filter {

 if [type] == “snoopy” {
   grok {
     match => { “message” => “%{SYSLOGTIMESTAMP:date} %{HOSTNAME:hostname} %{WORD:logger}\[%{INT}\]\: \[%{WORD}\:%{USERNAME:username} %{DATA} %{DATA} %{DATA} %{WORD}\:%{DATA:cwd} %{DATA}\]\: %{GREEDYDATA:exe_command}” }
   }
 if “_grokparsefailure” in [tags] {
   drop { }
 }
 }
}

Here we are generating these fields:
date: Timestamp at which log is generated
hostname: Name of host
logger: Name of logger which is generating logs in our case “snoopy”.
username: Name of user issuing the command
cwd: Absolute path of directory from where the command is executed
exe_command: Command that is executed by user with complete options

Place the above grok pattern in filter section of logstash configuration file which is at “/etc/logstash/conf.d/logstash.conf”. Also include logs from “/var/log/auth.log” to be shipped to logstash server from logstash agent at the client.

Creating Dashboard in Kibana

After that you can see these logs in kibana in “Discover” tab as shown in screenshot:

elkdiscover.png

In the left sidebar you can see all the fields via which you can filter including the fields we set in our grok pattern.Now in the search bar you can search according to specific field and its value. For example to search logs for vagrant user and all sudo commands executed by it, you will write the following query in search bar:
username:vagrant AND exe_command:sudo*
Then from the left sidebar add the fields you want to see, for example add “username”, “exe_command” and “cwd”, which will result to a table as shown below:

elktableselectedfields.png

Now save this search from the icon that is just adjacent to left bar with a suitable name. Then go to “Dashboard” menu and click on “plus” icon to add a dashboard. A screen will appear as shown:

adddashboard.png

Click on “Searches” tab and find your saved search and click over it. A resulting screen will appear which will be added to your dashboard as shown below:

dashboardadded.png

Here you can view tabular data for the sudo commands executed by vagrant user. Similarly you can add more searches by clicking on “plus icon” and add it to the same dashboard.Now save this dashboard by clicking on the “save” icon adjacent to search bar with a suitable name.After that you can easily load this dashboard by clicking on “load” icon adjacent to search bar.