Skip to content

Log levels

goodsign edited this page Oct 21, 2013 · 33 revisions

Introduction

The section represents our vision of the Seelog's level gradations, their meanings, and usage scopes. As we are tuning Seelog code according to our concepts, it is recommended to stick to the following rules.

Supported log levels

  • Trace - For pervasive information on states of all elementary constructs. Use 'Trace' for in-depth debugging to find problem parts of a function, to check values of temporary variables, etc.
  • Debug - For detailed system behavior reports and diagnostic messages to help to locate problems during development.
  • Info - For general information on the application's work. Use 'Info' level in your code so that you could leave it 'enabled' even in production. So it is a 'production log level'.
  • Warn - For indicating small errors, strange situations, failures that are automatically handled in a safe manner.
  • Error - For severe failures that affects application's workflow, not fatal, however (without forcing app shutdown).
  • Critical - For producing final messages before application’s death. Note: critical messages force immediate flush because in critical situation it is important to avoid log message losses if app crashes.
  • Off - A special log level used to turn off logging

Log level identifiers for config files

  • "trace"
  • "debug"
  • "info"
  • "warn"
  • "error"
  • "critical"

Examples of log messages

  • Trace
    • "Entered parse function validation block"
    • "Validation: entered second 'if'"
    • "Dictionary 'Dict' is empty. Using default value"
  • Debug
    • "Web page requested: http://somesite.com Params='...'"
    • "Response generated. Response size: 10000. Sending."
    • "New file received. Type:PNG Size:20000"
  • Info
    • "Web server restarted"
    • "Hourly statistics: Requested pages: 12345 Errors: 123 ..."
    • "Service paused. Waiting for 'resume' call"
  • Warn
    • "Cache corrupted for file='test.file'. Reading from back-end"
    • "Database 192.168.0.7/DB not responding. Using backup 192.168.0.8/DB"
    • "No response from statistics server. Statistics not sent"
  • Error
    • "Internal error. Cannot process request #12345 Error:...."
    • "Cannot perform login: credentials DB not responding"
  • Critical
    • "Critical panic received: .... Shutting down"
    • "Fatal error: ... App is shutting down to prevent data corruption or loss"

Example

Take a look at the example below which demonstrates conceptual usage of Seelog's levels.

NOTE 1: This example doesn't actually make any sense in terms of calculations. It just highlights the difference in log level usage contexts.

NOTE 2: Sometimes people confuse Info with Debug or even Trace. We tried to mark out the most striking cases where those are put. Please notice the 'Info' usage cases: It is a production log level and we let it play where no performance hit, even in production, is expected.

package main

import (
	log "github.com/cihub/seelog"
	"time"
	"errors"
)

type inputData struct {
	x, y int
}

type outputData struct {
	result int
	error bool
}

var inputs chan inputData
var outputs chan outputData
var criticalChan chan int

func internalCalculationFunc(x, y int) (result int, err error) {
	log.Debugf("calculating z. x:%d y:%d", x, y)
	z := y
	switch {
	case x == 3 :
		log.Trace("x == 3")
		panic("Failure.")
	case y == 1 :
		log.Trace("y == 1")
		return 0, errors.New("Error!")
	case y == 2 :
		log.Trace("y == 2")
		z = x
	default :
		log.Trace("default")
		z += x
	}
	log.Tracef("z:%d",z)
	retVal := z-3
	log.Debugf("Returning %d", retVal)
	
	return retVal, nil
}

func generateInputs(dest chan inputData) {
	time.Sleep(1e9)
	log.Debug("Sending 2 3")
	dest <- inputData{x : 2, y : 3}
	
	time.Sleep(1e9)
	log.Debug("Sending 2 1")
	dest <- inputData{x : 2, y : 1}
	
	time.Sleep(1e9)
	log.Debug("Sending 3 4")
	dest <- inputData{x : 3, y : 4}
	
	time.Sleep(1e9)
	log.Debug("Sending critical")
	criticalChan <- 1
}

func consumeResults(res chan outputData) {
	for {
		select {
			case <- outputs:
			// At this point we get and consume resultant value
		}
	}
}

func processInput(input inputData) {
	defer func() {
		if r := recover(); r != nil {
            log.Errorf("Unexpected error occurred: %v", r)
			outputs <- outputData{result : 0, error : true}
        }
	}()
	log.Infof("Received input signal. x:%d y:%d", input.x, input.y)	
	
	res, err := internalCalculationFunc(input.x, input.y)	
	if err != nil {
		log.Warnf("Error in calculation: %s", err.Error())
	}
	
	log.Infof("Returning result: %d error: %t", res, err != nil)		
	outputs <- outputData{result : res, error : err != nil}	
}

func main() {
	inputs = make(chan inputData)
	outputs = make(chan outputData)
	criticalChan = make(chan int)
	log.Info("App started.")
	
	go consumeResults(outputs)
	log.Info("Started receiving results.")
	
	go generateInputs(inputs)
	log.Info("Started sending signals.")
	
	for {
		select {
			case input := <- inputs:
				processInput(input)
			case <- criticalChan:
				log.Critical("Caught value from criticalChan: Go shut down.")
				panic("Shut down due to critical fault.")
		}	
	}
}