What is Log in backend

Log顾名思义就是纪录，通常在Backend当中会将可预期或非预期的错误记录在此，除此之外也会记录些测试用资料以及警讯资料用以帮忙我们除错/纪录/开发。

那Backend Log的产生都是发生在Server端，目前大部分的Backend设计也都透过API, Application，并采用Client/Broswer与Server的架构完成，也因此可将Backend Log分为三大种类

• Event Log
• Application Log
• Request Log

Event Log

定义使用者在介面上的操作，像是新增资料、上传档案、发送讯息等。，通常表示一个业务逻辑的执行与实现，那里头每次的动作可能会包含多次的API呼叫，而每次的呼叫都属於一项操作。Event Log的目的就是纪录使用者的操作记录，以此可以用来检测、除错与统计资料等。

Application Log

由Server执行过程中所产生的Log，用来追踪系统实际运行状况，与资料的流动情形。而且在Exception发生时就是纪录在此，好让後续可以追踪分析与解决。

Request Log

人如其名，就是Request在传递时所记录的讯息，但由於Requests繁多导致纪录成本庞大，因此大部分情况只会纪录HTTP Header甚至是不纪录Request，只有在发生Error时才会纪录完整Request资料。

Log level

TRACE < DEBUG < INFO < WARN < ERROR < FATAL < PANIC

Log除了类型以外也有优先序的差别，当log讯息等级高於你所设定的日志等级，
则该讯息不会纪录输出。

当你设定越高的层级，你的纪录成本也会越大，那通常在production environment只会预设为ERROR或是WARN而已。那下面就依照不同的Level依序介绍

TRACE

最高等级的log，主要用来追踪某些小事。

DEBUG

纪录有用的debug资讯。

INFO

当有些有用的事件发生时，会纪录的资讯。

WARN

警示讯息，虽然不会对系统有重大影响，但需要注意一下该讯息。

ERROR

发生了错误，但系统依旧在运作。

FATAL

最紧急的错误，一但发生需要立即hotflix。

PANIC

最低等级的log，当调用Panic时发生。

Logrus

这边我们选用github.com/sirupsen/logrus 这个相当多人使用的log package将Log实作在Gin Backend Server当中。那logrus也有着以下的几个优点:

1. 完全兼容於Golang的官方Log Module，logrus有着DEBUG、INFO、WARN、ERROR、FATAL与PANIC这六个级别，与Go的官方Modul相同。假使有些第三方套件或是其他专案是用官方的Log，之後可以无痛地迁移至logrus上。
2. 可以拓展的Hook机制，允许使用者能将log放到任意地方，像是本地储存空间、LogStash、ElasticSearch与Message Queue等。
3. 可选的Formatter，logrus内建两种输出格式，JSON与Text，如果还需要其他格式，则可以自己手动实现Interface Formatter来定义自己格式。

Installation

go get -u github.com/sirupsen/logrus

GIn with logrus

/app/middleware/log.go

package middleware

import (
	"fmt"
	"github.com/gin-gonic/gin"
	"github.com/sirupsen/logrus"
	"os"
	"path"
	"time"
)

func Logger() *logrus.Logger {
	now := time.Now()
	logFilePath := ""
	if dir, err := os.Getwd(); err == nil {
		logFilePath = dir + "/logs/"
	}
	if err := os.MkdirAll(logFilePath, 0777); err != nil {
		fmt.Println(err.Error())
	}
	logFileName := now.Format("2006-01-02") + ".log"

	fileName := path.Join(logFilePath, logFileName)
	if _, err := os.Stat(fileName); err != nil {
		if _, err := os.Create(fileName); err != nil {
			fmt.Println(err.Error())
		}
	}

	src, err := os.OpenFile(fileName, os.O_APPEND|os.O_WRONLY, os.ModeAppend)
	if err != nil {
		fmt.Println("err", err)
	}

	logger := logrus.New()
	logger.Out = src
	logger.SetLevel(logrus.DebugLevel)
	logger.SetFormatter(&logrus.TextFormatter{
		TimestampFormat: "2021-01-01 11:11:11",
	})
	return logger
}

func LoggerToFile() gin.HandlerFunc {
	logger := Logger()
	return func(c *gin.Context) {
		startTime := time.Now()
		c.Next()

		endTime := time.Now()
		latencyTime := endTime.Sub(startTime)
		reqMethod := c.Request.Method
		reqUri := c.Request.RequestURI
		statusCode := c.Writer.Status()
		clientIP := c.ClientIP()
		logger.Infof("| %3d | %13v | %15s | %s | %s |",
			statusCode,
			latencyTime,
			clientIP,
			reqMethod,
			reqUri,
		)
	}
}

• Logger(): 主要是设定输出档案的位置、输出格式、档案命名等设定，在init好LogFile之後藉由

logrus.New() 实体化一个logrus物件，并设定所需的log level与TIme Format，并将log写入LogFile之中。

• LoggerToFile(): Gin的log middleware，我们会将时间相关资讯与gin.Context中的Request Method, URL, StatusCode与IP等资讯也一并写入log之中。

main.go

	server := gin.Default()
	server.Use(middleware.LoggerToFile())
	server.Use(middleware.CORSMiddleware())
	server.GET("/hc", func(c *gin.Context) {
		c.String(http.StatusOK, fmt.Sprintf("Health Check"))
		middleware.Logger().WithFields(logrus.Fields{
			"name": "Flynn Sun",
		}).Info("Health Check", "Info")
	})
	

我们让Gin使用LoggerToFile()这个Middleware，并在health check endpoint当中写入INFO Level的log加以测试。

docker-compose.yaml

ironman-2021:
    container_name: ironman-2021
    ports:
      - "8080:8080"
    build:
      context: ./
      dockerfile: Dockerfile
    command: ./main
    restart: always
    networks:
      - backend-bridge
    depends_on:
      - postgresql
      - redis
    volumes:
    - ./logs/:/usr/local/go/src/ironman-2021/logs

我们在Gin的Container中将logs folder的log file都mount出来，让我们比较容易去观察与纪录log。

最後我们则是来启动docker-compose —build 并 GET http://localhost:8080/hc 进行测试。

然後会在/logs/2021-10-09.log当中得到以下内容

time="90910-10-10 1010:1010:1010" level=info msg="Health CheckInfo" name="Flynn Sun"
time="90910-10-10 1010:1010:1010" level=info msg="| 200 |      6.7669ms |   192.168.160.1 | GET | /hc |"

这也证实我们的logger实装完成！

Summary

Logger在Backend Server当中是必不可缺的一环，因为再怎麽完美的系统也一定会有着漏洞，如果届时没有logger的话，会相当难找到问题所在！

这次的程序码我也会放在下方连结，欢迎大家享用。

https://github.com/Neskem/Ironman-2021/tree/Day-26