aboutsummaryrefslogtreecommitdiffstats
path: root/logger
diff options
context:
space:
mode:
authorobscuren <geffobscura@gmail.com>2014-10-31 19:56:05 +0800
committerobscuren <geffobscura@gmail.com>2014-10-31 19:56:05 +0800
commitb1c247231b11f313ca0eedff75ea563926d23f68 (patch)
tree48b2136cb65e69cb79ffac80f3cc3fdf9dba1cc8 /logger
parentfd9da72536b73351bbcdc1e9dbbbb8c0e4bfb21b (diff)
downloadgo-tangerine-b1c247231b11f313ca0eedff75ea563926d23f68.tar
go-tangerine-b1c247231b11f313ca0eedff75ea563926d23f68.tar.gz
go-tangerine-b1c247231b11f313ca0eedff75ea563926d23f68.tar.bz2
go-tangerine-b1c247231b11f313ca0eedff75ea563926d23f68.tar.lz
go-tangerine-b1c247231b11f313ca0eedff75ea563926d23f68.tar.xz
go-tangerine-b1c247231b11f313ca0eedff75ea563926d23f68.tar.zst
go-tangerine-b1c247231b11f313ca0eedff75ea563926d23f68.zip
ethlog => logger
Diffstat (limited to 'logger')
-rw-r--r--logger/example_test.go21
-rw-r--r--logger/loggers.go248
-rw-r--r--logger/loggers_test.go174
3 files changed, 443 insertions, 0 deletions
diff --git a/logger/example_test.go b/logger/example_test.go
new file mode 100644
index 000000000..c624252b8
--- /dev/null
+++ b/logger/example_test.go
@@ -0,0 +1,21 @@
+package logger
+
+import "os"
+
+func ExampleLogger() {
+ logger := NewLogger("TAG")
+ logger.Infoln("so awesome") // prints [TAG] so awesome
+ logger.Infof("this %q is raw", "coin") // prints [TAG] this "coin" is raw
+}
+
+func ExampleLogSystem() {
+ filename := "test.log"
+ file, _ := os.OpenFile(filename, os.O_RDWR|os.O_CREATE, os.ModePerm)
+ fileLog := NewStdLogSystem(file, 0, WarnLevel)
+ AddLogSystem(fileLog)
+
+ stdoutLog := NewStdLogSystem(os.Stdout, 0, WarnLevel)
+ AddLogSystem(stdoutLog)
+
+ NewLogger("TAG").Warnln("reactor meltdown") // writes to both logs
+}
diff --git a/logger/loggers.go b/logger/loggers.go
new file mode 100644
index 000000000..1bf7bfa0e
--- /dev/null
+++ b/logger/loggers.go
@@ -0,0 +1,248 @@
+/*
+Package logger implements a multi-output leveled logger.
+
+Other packages use tagged logger to send log messages to shared
+(process-wide) logging engine. The shared logging engine dispatches to
+multiple log systems. The log level can be set separately per log
+system.
+
+Logging is asynchronous and does not block the caller. Message
+formatting is performed by the caller goroutine to avoid incorrect
+logging of mutable state.
+*/
+package logger
+
+import (
+ "fmt"
+ "io"
+ "log"
+ "os"
+ "sync"
+ "sync/atomic"
+)
+
+// LogSystem is implemented by log output devices.
+// All methods can be called concurrently from multiple goroutines.
+type LogSystem interface {
+ GetLogLevel() LogLevel
+ SetLogLevel(i LogLevel)
+ LogPrint(LogLevel, string)
+}
+
+type message struct {
+ level LogLevel
+ msg string
+}
+
+type LogLevel uint8
+
+const (
+ // Standard log levels
+ Silence LogLevel = iota
+ ErrorLevel
+ WarnLevel
+ InfoLevel
+ DebugLevel
+ DebugDetailLevel
+)
+
+var (
+ logMessageC = make(chan message)
+ addSystemC = make(chan LogSystem)
+ flushC = make(chan chan struct{})
+ resetC = make(chan chan struct{})
+)
+
+func init() {
+ go dispatchLoop()
+}
+
+// each system can buffer this many messages before
+// blocking incoming log messages.
+const sysBufferSize = 500
+
+func dispatchLoop() {
+ var (
+ systems []LogSystem
+ systemIn []chan message
+ systemWG sync.WaitGroup
+ )
+ bootSystem := func(sys LogSystem) {
+ in := make(chan message, sysBufferSize)
+ systemIn = append(systemIn, in)
+ systemWG.Add(1)
+ go sysLoop(sys, in, &systemWG)
+ }
+
+ for {
+ select {
+ case msg := <-logMessageC:
+ for _, c := range systemIn {
+ c <- msg
+ }
+
+ case sys := <-addSystemC:
+ systems = append(systems, sys)
+ bootSystem(sys)
+
+ case waiter := <-resetC:
+ // reset means terminate all systems
+ for _, c := range systemIn {
+ close(c)
+ }
+ systems = nil
+ systemIn = nil
+ systemWG.Wait()
+ close(waiter)
+
+ case waiter := <-flushC:
+ // flush means reboot all systems
+ for _, c := range systemIn {
+ close(c)
+ }
+ systemIn = nil
+ systemWG.Wait()
+ for _, sys := range systems {
+ bootSystem(sys)
+ }
+ close(waiter)
+ }
+ }
+}
+
+func sysLoop(sys LogSystem, in <-chan message, wg *sync.WaitGroup) {
+ for msg := range in {
+ if sys.GetLogLevel() >= msg.level {
+ sys.LogPrint(msg.level, msg.msg)
+ }
+ }
+ wg.Done()
+}
+
+// Reset removes all active log systems.
+// It blocks until all current messages have been delivered.
+func Reset() {
+ waiter := make(chan struct{})
+ resetC <- waiter
+ <-waiter
+}
+
+// Flush waits until all current log messages have been dispatched to
+// the active log systems.
+func Flush() {
+ waiter := make(chan struct{})
+ flushC <- waiter
+ <-waiter
+}
+
+// AddLogSystem starts printing messages to the given LogSystem.
+func AddLogSystem(sys LogSystem) {
+ addSystemC <- sys
+}
+
+// A Logger prints messages prefixed by a given tag. It provides named
+// Printf and Println style methods for all loglevels. Each ethereum
+// component should have its own logger with a unique prefix.
+type Logger struct {
+ tag string
+}
+
+func NewLogger(tag string) *Logger {
+ return &Logger{"[" + tag + "] "}
+}
+
+func (logger *Logger) sendln(level LogLevel, v ...interface{}) {
+ logMessageC <- message{level, logger.tag + fmt.Sprintln(v...)}
+}
+
+func (logger *Logger) sendf(level LogLevel, format string, v ...interface{}) {
+ logMessageC <- message{level, logger.tag + fmt.Sprintf(format, v...)}
+}
+
+// Errorln writes a message with ErrorLevel.
+func (logger *Logger) Errorln(v ...interface{}) {
+ logger.sendln(ErrorLevel, v...)
+}
+
+// Warnln writes a message with WarnLevel.
+func (logger *Logger) Warnln(v ...interface{}) {
+ logger.sendln(WarnLevel, v...)
+}
+
+// Infoln writes a message with InfoLevel.
+func (logger *Logger) Infoln(v ...interface{}) {
+ logger.sendln(InfoLevel, v...)
+}
+
+// Debugln writes a message with DebugLevel.
+func (logger *Logger) Debugln(v ...interface{}) {
+ logger.sendln(DebugLevel, v...)
+}
+
+// DebugDetailln writes a message with DebugDetailLevel.
+func (logger *Logger) DebugDetailln(v ...interface{}) {
+ logger.sendln(DebugDetailLevel, v...)
+}
+
+// Errorf writes a message with ErrorLevel.
+func (logger *Logger) Errorf(format string, v ...interface{}) {
+ logger.sendf(ErrorLevel, format, v...)
+}
+
+// Warnf writes a message with WarnLevel.
+func (logger *Logger) Warnf(format string, v ...interface{}) {
+ logger.sendf(WarnLevel, format, v...)
+}
+
+// Infof writes a message with InfoLevel.
+func (logger *Logger) Infof(format string, v ...interface{}) {
+ logger.sendf(InfoLevel, format, v...)
+}
+
+// Debugf writes a message with DebugLevel.
+func (logger *Logger) Debugf(format string, v ...interface{}) {
+ logger.sendf(DebugLevel, format, v...)
+}
+
+// DebugDetailf writes a message with DebugDetailLevel.
+func (logger *Logger) DebugDetailf(format string, v ...interface{}) {
+ logger.sendf(DebugDetailLevel, format, v...)
+}
+
+// Fatalln writes a message with ErrorLevel and exits the program.
+func (logger *Logger) Fatalln(v ...interface{}) {
+ logger.sendln(ErrorLevel, v...)
+ Flush()
+ os.Exit(0)
+}
+
+// Fatalf writes a message with ErrorLevel and exits the program.
+func (logger *Logger) Fatalf(format string, v ...interface{}) {
+ logger.sendf(ErrorLevel, format, v...)
+ Flush()
+ os.Exit(0)
+}
+
+// NewStdLogSystem creates a LogSystem that prints to the given writer.
+// The flag values are defined package log.
+func NewStdLogSystem(writer io.Writer, flags int, level LogLevel) LogSystem {
+ logger := log.New(writer, "", flags)
+ return &stdLogSystem{logger, uint32(level)}
+}
+
+type stdLogSystem struct {
+ logger *log.Logger
+ level uint32
+}
+
+func (t *stdLogSystem) LogPrint(level LogLevel, msg string) {
+ t.logger.Print(msg)
+}
+
+func (t *stdLogSystem) SetLogLevel(i LogLevel) {
+ atomic.StoreUint32(&t.level, uint32(i))
+}
+
+func (t *stdLogSystem) GetLogLevel() LogLevel {
+ return LogLevel(atomic.LoadUint32(&t.level))
+}
diff --git a/logger/loggers_test.go b/logger/loggers_test.go
new file mode 100644
index 000000000..adc4df016
--- /dev/null
+++ b/logger/loggers_test.go
@@ -0,0 +1,174 @@
+package logger
+
+import (
+ "io/ioutil"
+ "math/rand"
+ "os"
+ "sync"
+ "testing"
+ "time"
+)
+
+type TestLogSystem struct {
+ mutex sync.Mutex
+ output string
+ level LogLevel
+}
+
+func (ls *TestLogSystem) LogPrint(level LogLevel, msg string) {
+ ls.mutex.Lock()
+ ls.output += msg
+ ls.mutex.Unlock()
+}
+
+func (ls *TestLogSystem) SetLogLevel(i LogLevel) {
+ ls.mutex.Lock()
+ ls.level = i
+ ls.mutex.Unlock()
+}
+
+func (ls *TestLogSystem) GetLogLevel() LogLevel {
+ ls.mutex.Lock()
+ defer ls.mutex.Unlock()
+ return ls.level
+}
+
+func (ls *TestLogSystem) CheckOutput(t *testing.T, expected string) {
+ ls.mutex.Lock()
+ output := ls.output
+ ls.mutex.Unlock()
+ if output != expected {
+ t.Errorf("log output mismatch:\n got: %q\n want: %q\n", output, expected)
+ }
+}
+
+type blockedLogSystem struct {
+ LogSystem
+ unblock chan struct{}
+}
+
+func (ls blockedLogSystem) LogPrint(level LogLevel, msg string) {
+ <-ls.unblock
+ ls.LogSystem.LogPrint(level, msg)
+}
+
+func TestLoggerFlush(t *testing.T) {
+ Reset()
+
+ logger := NewLogger("TEST")
+ ls := blockedLogSystem{&TestLogSystem{level: WarnLevel}, make(chan struct{})}
+ AddLogSystem(ls)
+ for i := 0; i < 5; i++ {
+ // these writes shouldn't hang even though ls is blocked
+ logger.Errorf(".")
+ }
+
+ beforeFlush := time.Now()
+ time.AfterFunc(80*time.Millisecond, func() { close(ls.unblock) })
+ Flush() // this should hang for approx. 80ms
+ if blockd := time.Now().Sub(beforeFlush); blockd < 80*time.Millisecond {
+ t.Errorf("Flush didn't block long enough, blocked for %v, should've been >= 80ms", blockd)
+ }
+
+ ls.LogSystem.(*TestLogSystem).CheckOutput(t, "[TEST] .[TEST] .[TEST] .[TEST] .[TEST] .")
+}
+
+func TestLoggerPrintln(t *testing.T) {
+ Reset()
+
+ logger := NewLogger("TEST")
+ testLogSystem := &TestLogSystem{level: WarnLevel}
+ AddLogSystem(testLogSystem)
+ logger.Errorln("error")
+ logger.Warnln("warn")
+ logger.Infoln("info")
+ logger.Debugln("debug")
+ Flush()
+
+ testLogSystem.CheckOutput(t, "[TEST] error\n[TEST] warn\n")
+}
+
+func TestLoggerPrintf(t *testing.T) {
+ Reset()
+
+ logger := NewLogger("TEST")
+ testLogSystem := &TestLogSystem{level: WarnLevel}
+ AddLogSystem(testLogSystem)
+ logger.Errorf("error to %v\n", []int{1, 2, 3})
+ logger.Warnf("warn %%d %d", 5)
+ logger.Infof("info")
+ logger.Debugf("debug")
+ Flush()
+ testLogSystem.CheckOutput(t, "[TEST] error to [1 2 3]\n[TEST] warn %d 5")
+}
+
+func TestMultipleLogSystems(t *testing.T) {
+ Reset()
+
+ logger := NewLogger("TEST")
+ testLogSystem0 := &TestLogSystem{level: ErrorLevel}
+ testLogSystem1 := &TestLogSystem{level: WarnLevel}
+ AddLogSystem(testLogSystem0)
+ AddLogSystem(testLogSystem1)
+ logger.Errorln("error")
+ logger.Warnln("warn")
+ Flush()
+
+ testLogSystem0.CheckOutput(t, "[TEST] error\n")
+ testLogSystem1.CheckOutput(t, "[TEST] error\n[TEST] warn\n")
+}
+
+func TestFileLogSystem(t *testing.T) {
+ Reset()
+
+ logger := NewLogger("TEST")
+ filename := "test.log"
+ file, _ := os.OpenFile(filename, os.O_RDWR|os.O_CREATE, os.ModePerm)
+ testLogSystem := NewStdLogSystem(file, 0, WarnLevel)
+ AddLogSystem(testLogSystem)
+ logger.Errorf("error to %s\n", filename)
+ logger.Warnln("warn")
+ Flush()
+ contents, _ := ioutil.ReadFile(filename)
+ output := string(contents)
+ if output != "[TEST] error to test.log\n[TEST] warn\n" {
+ t.Error("Expected contents of file 'test.log': '[TEST] error to test.log\\n[TEST] warn\\n', got ", output)
+ } else {
+ os.Remove(filename)
+ }
+}
+
+func TestNoLogSystem(t *testing.T) {
+ Reset()
+
+ logger := NewLogger("TEST")
+ logger.Warnln("warn")
+ Flush()
+}
+
+func TestConcurrentAddSystem(t *testing.T) {
+ rand.Seed(time.Now().Unix())
+ Reset()
+
+ logger := NewLogger("TEST")
+ stop := make(chan struct{})
+ writer := func() {
+ select {
+ case <-stop:
+ return
+ default:
+ logger.Infoln("foo")
+ Flush()
+ }
+ }
+
+ go writer()
+ go writer()
+
+ stopTime := time.Now().Add(100 * time.Millisecond)
+ for time.Now().Before(stopTime) {
+ time.Sleep(time.Duration(rand.Intn(20)) * time.Millisecond)
+ AddLogSystem(NewStdLogSystem(ioutil.Discard, 0, InfoLevel))
+ }
+ close(stop)
+}