Logging #5: Log Entry Builder

Problem

Repetitive code when logging contextual data (like function’s parameters, request’s header).

Solution

Use Builder design pattern to create a log to be emitted.

Example

Let’s consider that we have following HTTP request handler (full code):

func OrderHandler(w http.ResponseWriter, r *http.Request) {
	var request struct {
		Product  string `json:"product"`
		Quantity int    `json:"quantity"`
	}
	if err := json.NewDecoder(r.Body).Decode(&request); err != nil {
		log.Printf(`err="%s, parsing JSON failed"`, err.Error())
		w.WriteHeader(http.StatusBadRequest)
		return
	}
	if request.Quantity < 1 {
		log.Printf(`request="%v, quantity is non-positive"`, request)
		w.WriteHeader(http.StatusBadRequest)
		return
	}
	price, err := order(request.Product, request.Quantity)
	if err != nil {
		log.Printf(`request="%v, err="%s, order failed"`, request, err.Error())
		w.WriteHeader(http.StatusInternalServerError)
		return
	}

	log.Printf(`request="%v, price=%.2f, order submitted"`, request, price)
	fmt.Fprintf(w, "%.2f", price)
}

As we can see there is a lot of repetitive code when adding the parsed request to the log.

Here is is how it can be refactored to use the log entry builder pattern (full code):

func OrderHandler(w http.ResponseWriter, r *http.Request) {
	log := logrus.NewEntry(logrus.StandardLogger())
	var request struct {
		Product  string `json:"product"`
		Quantity int    `json:"quantity"`
	}
	if err := json.NewDecoder(r.Body).Decode(&request); err != nil {
		log.WithError(err).Warn("parsing JSON failed")
		w.WriteHeader(http.StatusBadRequest)
		return
	}
	log = log.WithField("request", request)
	if request.Quantity < 1 {
		log.Warn("quantity is non-positive")
		w.WriteHeader(http.StatusBadRequest)
		return
	}
	price, err := order(request.Product, request.Quantity)
	if err != nil {
		log.WithError(err).Error("order failed")
		w.WriteHeader(http.StatusInternalServerError)
		return
	}
	log.WithField("price", price).Info("order submitted")
	fmt.Fprintf(w, "%.2f", price)
}

logrus has been used, because it has built-in log entry builder API.

Advantages

1. Less duplication e when logging the same data in different place.
2. Separation of logging different junks of data.
3. Slightly more readable code. Especially when combined with structured logging.

Disadvantages

1. Forces to use some non-standard logging library or create your own abstractions.
2. Usually results in more lines of code.

Logging series

• #1: Demo Application
• #2: It Depends
• #3: Structured Logging
• #4: Log Levels
• #5: Log Entry Builder
• #6: Correlation Log Field
• #7: Contextual Error Data Log Field
• #8: Logger Output
•  #9: Observability via Logging