Log levels

Introduction

This document represents our vision of the sealog's level gradations, level meanings, and usage scopes. This topic is still debatable as we are tuning the sealog code but it is recommended not to deviate from our concepts too much.

Supported log levels

• Trace - Pervasive information about states of all elementary constructs. Use 'Trace' for deep debugging to find a problem part of a function, to check values of temporary variables
• Debug - Produces detailed report on system behavior. Diagnostically helpful messages that let you find problems during development
• Info - General information about app work. You should use 'Info' level in your code so that you could leave it 'enabled' even in production. So it is a 'production log level'
• Warn - Small errors, strange situations, failures that are automatically handled in a safe manner
• Error - Serious failure that affects application logic. Not fatal, however, doesn't force app shutdown
• Critical - Final message before app’s death
• Off - A special log level used to turn off logging

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 working example which demonstrates conceptual usage of sealog's levels.

NOTE 1: This example doesn't actually make any sense in terms of calculations. It's just highlight the difference in log level usage contexts. NOTE 2: We know that there is a 'time.Sleep(1e9)' between every input. That's why we use 'Info'. But we don't want you to use 'Info' for frequent external inputs, because 'Info' is a 'production log level' and shouldn't affect performance in production, when enabled.

package main

import (
	log "github.com/cihub/sealog"
	"os"
	"time"
)

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 os.Error) {
	log.Debug("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, os.NewError("Error!")
	case y == 2 :
		log.Trace("y == 2")
		z = x
	default :
		log.Trace("default")
		z += x
	}
	log.Trace("z:%d",z)
	retVal := z-3
	log.Debug("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.Error("Unexpected error occurred: %v", r)
			outputs <- outputData{result : 0, error : true}
                }
	}()
	log.Info("Received input signal. x:%d y:%d", input.x, input.y)

	res, err := internalCalculationFunc(input.x, input.y)	
	if err != nil {
		log.Warn("Error in calculation: %s", err.String())
	}
	
	log.Info("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.")
		}	
	}
}