Basic logging in Echo Golang

Phung Chi Huy — Sun, 29 Oct 2023 15:08:42 +0000

As we know, Echo has a JSON-format logging. That mean every line of logs is formatted as JSON. This is convenient for other services to read the log. However, in a standalone server, this is not readable because it’s hard for developer to debug.

In this blog, I will setup a project with a basic logger as a reference. If you have any better approach, please feel free to discuss with me. Thank you in advance.

Installation

Golang 1.21.1
Zerolog — A logging library of Go
Echo — A Golang web framework

Folder tree

Your root
├── common
│   ├── middlewares.go
│   └── logging.go
├── go.mod
├── go.sum
└── main.go

1. Getting started

First of all, we need to initialize a go module for our project by under command.

$ go mod init <name>

Then, we add some libraries in the installation section.

go get github.com/labstack/echo/v4
go get github.com/rs/zerolog/log

Create a main.go with below code.

package main

import (
 "net/http"

 "github.com/labstack/echo/v4"
)

func main() {
 e := echo.New()

 e.GET("/", func(c echo.Context) error {
  return c.String(http.StatusOK, "Hello, World!")
 })

 common.Logger.LogInfo().Msg(e.Start(":9000").Error())
}

Run the command: go run main.go

Then, we open a browser and go to http://localhost:9000. The output is:

Hello, World!

2. Create a logger

Create file common/logging.go

package common

import (
 "fmt"
 "os"
 "strings"
 "time"

 "github.com/rs/zerolog"
)

type MyLogger struct {
 zerolog.Logger
}

var Logger MyLogger

func NewLogger() MyLogger {
  // create output configuration
  output := zerolog.ConsoleWriter{Out: os.Stdout, TimeFormat: time.RFC3339}

  // Format level: fatal, error, debug, info, warn
  output.FormatLevel = func(i interface{}) string {
    return strings.ToUpper(fmt.Sprintf("| %-6s|", i))
  }
  output.FormatFieldName = func(i interface{}) string {
    return fmt.Sprintf("%s:", i)
  }
  output.FormatFieldValue = func(i interface{}) string {
    return fmt.Sprintf("%s", i)
  }

  // format error
  output.FormatErrFieldName = func(i interface{}) string {
    return fmt.Sprintf("%s: ", i)
  }

  zerolog := zerolog.New(output).With().Caller().Timestamp().Logger()
  Logger = MyLogger{zerolog}
  return Logger
}

func (l *MyLogger) LogInfo() *zerolog.Event {
 return l.Logger.Info()
}

func (l *MyLogger) LogError() *zerolog.Event {
 return l.Logger.Error()
}

func (l *MyLogger) LogDebug() *zerolog.Event {
 return l.Logger.Debug()
}

func (l *MyLogger) LogWarn() *zerolog.Event {
 return l.Logger.Warn()
}

func (l *MyLogger) LogFatal() *zerolog.Event {
 return l.Logger.Fatal()
}

3. Create a middleware to log requests

Create a file common/middlewares.go

package common

import (
 "github.com/labstack/echo/v4"
)

func LoggingMiddleware(next echo.HandlerFunc) echo.HandlerFunc {
 return func(c echo.Context) error {
  // log the request
  Logger.LogInfo().Fields(map[string]interface{}{
   "method": c.Request().Method,
   "uri":    c.Request().URL.Path,
   "query":  c.Request().URL.RawQuery,
  }).Msg("Request")

  // call the next middleware/handler
  err := next(c)
  if err != nil {
   Logger.LogError().Fields(map[string]interface{}{
    "error": err.Error(),
   }).Msg("Response")
   return err
  }

  return nil
 }
}

4. Add the LoggingMiddleware to the main function

package main

import (
 "net/http"

 "github.com/labstack/echo/v4"
 "huy.me/common"
)

func main() {
 e := echo.New()

 // logger
 common.NewLogger() // new
 e.Use(common.LoggingMiddleware) // new

 e.GET("/", func(c echo.Context) error {
  return c.String(http.StatusOK, "Hello, World!")
 })

 common.Logger.LogInfo().Msg(e.Start(":9000").Error())
}

5. Re-run your app

After step 4, re-run your project by the command:

go run main.go

Go to the browser and access the old URL http://localhost:9000. Then check your terminal, the log will be the same with the below image.

Add a mock authentication middleware to see log

In common/middlewares.go

package common

import (
 "github.com/labstack/echo/v4"
 "golang.org/x/exp/slices"
)

func LoggingMiddleware(next echo.HandlerFunc) echo.HandlerFunc {
 return func(c echo.Context) error {
  Logger.LogInfo().Fields(map[string]interface{}{
   "method": c.Request().Method,
   "uri":    c.Request().URL.Path,
   "query":  c.Request().URL.RawQuery,
  }).Msg("Request")

  err := next(c)
  if err != nil {
   Logger.LogError().Fields(map[string]interface{}{
    "error": err.Error(),
   }).Msg("Response")
   return err
  }

  return nil
 }
}

// new code here
func AuthMiddleware(next echo.HandlerFunc) echo.HandlerFunc {
 return func(c echo.Context) error {
  Logger.LogInfo().Msg("Authenticating...")
  // Add authentication logic here

  // after process authentication logic, 
  // call next(c) to pass to the next middleware
  return next(c)
 }
}

Then, register AuthMiddleware function to the Echo instance.

package main

import (
 "net/http"

 "github.com/labstack/echo/v4"
 "huy.me/common"
)

func main() {
 e := echo.New()

 // logger
 common.NewLogger()
 e.Use(common.LoggingMiddleware, common.AuthMiddleware) // new

 e.GET("/", func(c echo.Context) error {
  return c.String(http.StatusOK, "Hello, World!")
 })

 common.Logger.LogInfo().Msg(e.Start(":9000").Error())
}

Notice: The order of middlewares will affect the log. In the above code, the LoggingMiddleware will come first, then AuthMiddleware.

Now the log will something like below.

Thank you for reading :)

DEV Community: Phung Chi Huy