02 Logger and Leveling with Logrus in Golang

In the previous article we created a new project to dive deeper into Golang Logging, so now we will try to see how the log is initialized. For this lesson we will try it out using a unit test function so that it is easier to declare.

Initializing the Logger

First, create a file called logger_test.go and fill it with the code below.

1func Test_Logger(t *testing.T) {
2	logger := logrus.New()
3
4	logger.Println("Halo this is log using logrus")
5	logger.Infoln("hello this is log using logrus")
6	fmt.Println("hello this is using print log")
7}

When this unit test file is run, the output will look like the following.

1=== RUN   Test_Logger
2time="2024-04-21T08:57:59+07:00" level=info msg="Halo this is log using logrus"
3time="2024-04-21T08:57:59+07:00" level=info msg="hello this is log using logrus"
4hello this is using print log
5--- PASS: Test_Logger (0.00s)
6PASS
7ok      github.com/santekno/learn-golang-logging        0.482s

We can see the difference when printing a log with an ordinary print: there are several additional fields that provide information about the time, level, and message. This indicates that every piece of information produced by this Logging shows the time it was printed, the level of the displayed information, and the message we want to convey through the Logger.

Understanding Logging Levels

As we saw in the result of the example above, Logging displays Level information. What is a level? A level in Logging is very important, in fact it is the most important part of the Logging mechanism. The level determines the priority or type of an event in the system or service we build. It consists of several points, ranging from the lowest level up to the highest level.

The Logrus package already supports a great many levels, as you can see in the table below.

In that table, the higher the level, as seen from its number, the more fatal the information it provides or the more serious the problem in our system, which needs attention or possibly even a fix. Therefore, when we apply Logger leveling, we need to pay attention to which events require the error, info, warning, or fatal levels, because this gives us as developers information that makes it much easier to trace or debug problems in the system.

Alright, let’s try to distinguish between each level by experimenting with the code below.

 1package main
 2
 3import (
 4	"testing"
 5
 6	"github.com/sirupsen/logrus"
 7)
 8
 9func TestLeveling(t *testing.T) {
10	logger := logrus.New()
11
12	logger.Trace("this is using trace level")
13	logger.Debug("this is using debug level")
14	logger.Info("this is using info level")
15	logger.Warn("this is using warn level")
16	logger.Error("this is using error level")
17}

In the code above we do not include the fatal and panic logs because at those levels the system will exit, so we will only test up to the error level. We can see the result after running the TestLeveling unit test below.

1=== RUN   TestLeveling
2time="2024-04-21T09:22:38+07:00" level=info msg="this is using info level"
3time="2024-04-21T09:22:38+07:00" level=warning msg="this is using warn level"
4time="2024-04-21T09:22:38+07:00" level=error msg="this is using error level"
5--- PASS: TestLeveling (0.00s)
6PASS
7ok      github.com/santekno/learn-golang-logging        0.396s

Notice that the information at the trace and debug levels does not appear or is not printed by the logger. Why does this happen? Because of the Logging level: when we initialize it by calling

1logger := logrus.New()

the default level used is Info, meaning only events at the info priority and above will be printed to the log. So, to display levels down to trace, we need to change the logging level using

1logger.SetLevel(/* the level to be printed */)

Let’s add that code so it looks like the following, and run the unit test below again.

 1func TestLeveling(t *testing.T) {
 2	logger := logrus.New()
 3	logger.SetLevel(logrus.TraceLevel)
 4
 5	logger.Trace("this is using trace level")
 6	logger.Debug("this is using debug level")
 7	logger.Info("this is using info level")
 8	logger.Warn("this is using warn level")
 9	logger.Error("this is using error level")
10}

It will then print all logging levels, starting from the trace level and above.

1=== RUN   TestLeveling
2time="2024-04-21T09:29:41+07:00" level=trace msg="this is using trace level"
3time="2024-04-21T09:29:41+07:00" level=debug msg="this is using debug level"
4time="2024-04-21T09:29:41+07:00" level=info msg="this is using info level"
5time="2024-04-21T09:29:41+07:00" level=warning msg="this is using warn level"
6time="2024-04-21T09:29:41+07:00" level=error msg="this is using error level"
7--- PASS: TestLeveling (0.00s)
8PASS
9ok      github.com/santekno/learn-golang-logging        0.375s