From 4e95cecfb999425e40b0c071b9768b1654167fe2 Mon Sep 17 00:00:00 2001
From: Felix Lange <fjl@twurst.com>
Date: Tue, 14 Oct 2014 14:29:04 +0200
Subject: [PATCH 01/15] ethlog: improve dispatch concurrency

This also fixes a deadlock in the tests.
---
 ethlog/loggers.go | 111 ++++++++++++++++++++++++----------------------
 1 file changed, 57 insertions(+), 54 deletions(-)

diff --git a/ethlog/loggers.go b/ethlog/loggers.go
index b2760534b6..34561853a9 100644
--- a/ethlog/loggers.go
+++ b/ethlog/loggers.go
@@ -29,20 +29,6 @@ func newPrintfLogMessage(level LogLevel, tag string, format string, v ...interfa
 	return &logMessage{level, true, fmt.Sprintf("[%s] %s", tag, fmt.Sprintf(format, v...))}
 }
 
-func (msg *logMessage) send(logger LogSystem) {
-	if msg.format {
-		logger.Printf(msg.msg)
-	} else {
-		logger.Println(msg.msg)
-	}
-}
-
-var logMessages chan (*logMessage)
-var logSystems []LogSystem
-var quit chan chan error
-var drained chan bool
-var mutex = sync.Mutex{}
-
 type LogLevel uint8
 
 const (
@@ -54,56 +40,80 @@ const (
 	DebugDetailLevel
 )
 
-func dispatch(msg *logMessage) {
-	for _, logSystem := range logSystems {
-		if logSystem.GetLogLevel() >= msg.LogLevel {
-			msg.send(logSystem)
-		}
-	}
+var (
+	mutex      sync.RWMutex // protects logSystems
+	logSystems []LogSystem
+
+	logMessages  = make(chan *logMessage)
+	drainWaitReq = make(chan chan struct{})
+)
+
+func init() {
+	go dispatchLoop()
 }
 
-// log messages are dispatched to log writers
-func start() {
+func dispatchLoop() {
+	var drainWait []chan struct{}
+	dispatchDone := make(chan struct{})
+	pending := 0
 	for {
 		select {
-		case status := <-quit:
-			status <- nil
-			return
 		case msg := <-logMessages:
-			dispatch(msg)
-		default:
-			drained <- true // this blocks until a message is sent to the queue
+			go dispatch(msg, dispatchDone)
+			pending++
+		case waiter := <-drainWaitReq:
+			if pending == 0 {
+				close(waiter)
+			} else {
+				drainWait = append(drainWait, waiter)
+			}
+		case <-dispatchDone:
+			pending--
+			if pending == 0 {
+				for _, c := range drainWait {
+					close(c)
+				}
+				drainWait = nil
+			}
 		}
 	}
 }
 
+func dispatch(msg *logMessage, done chan<- struct{}) {
+	mutex.RLock()
+	for _, sys := range logSystems {
+		if sys.GetLogLevel() >= msg.LogLevel {
+			if msg.format {
+				sys.Printf(msg.msg)
+			} else {
+				sys.Println(msg.msg)
+			}
+		}
+	}
+	mutex.RUnlock()
+	done <- struct{}{}
+}
+
+// send delivers a message to all installed log
+// systems. it doesn't wait for the message to be
+// written.
 func send(msg *logMessage) {
 	logMessages <- msg
-	select {
-	case <-drained:
-	default:
-	}
 }
 
+// Reset removes all registered log systems.
 func Reset() {
 	mutex.Lock()
-	defer mutex.Unlock()
-	if logSystems != nil {
-		status := make(chan error)
-		quit <- status
-		select {
-		case <-drained:
-		default:
-		}
-		<-status
-	}
+	logSystems = nil
+	mutex.Unlock()
 }
 
-// waits until log messages are drained (dispatched to log writers)
+// Flush waits until all current log messages have been dispatched to
+// the active log systems.
 func Flush() {
-	if logSystems != nil {
-		<-drained
-	}
+	waiter := make(chan struct{})
+	drainWaitReq <- waiter
+	<-waiter
 }
 
 type Logger struct {
@@ -115,16 +125,9 @@ func NewLogger(tag string) *Logger {
 }
 
 func AddLogSystem(logSystem LogSystem) {
-	var mutex = &sync.Mutex{}
 	mutex.Lock()
-	defer mutex.Unlock()
-	if logSystems == nil {
-		logMessages = make(chan *logMessage, 10)
-		quit = make(chan chan error, 1)
-		drained = make(chan bool, 1)
-		go start()
-	}
 	logSystems = append(logSystems, logSystem)
+	mutex.Unlock()
 }
 
 func (logger *Logger) sendln(level LogLevel, v ...interface{}) {

From dac128a029ee8d80d4ebdad64b24506c03d55e63 Mon Sep 17 00:00:00 2001
From: Felix Lange <fjl@twurst.com>
Date: Tue, 14 Oct 2014 14:31:33 +0200
Subject: [PATCH 02/15] ethlog: fix test compilation error

---
 ethlog/loggers_test.go | 1 -
 1 file changed, 1 deletion(-)

diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go
index a9b1463e7e..2b0d1fb1d0 100644
--- a/ethlog/loggers_test.go
+++ b/ethlog/loggers_test.go
@@ -54,7 +54,6 @@ func TestLoggerPrintln(t *testing.T) {
 	Flush()
 	Reset()
 	output := testLogSystem.Output
-	fmt.Println(quote(output))
 	if output != "[TEST] error\n[TEST] warn\n" {
 		t.Error("Expected logger output '[TEST] error\\n[TEST] warn\\n', got ", output)
 	}

From 3b1296077b2f814bf4bf478aea63503d18ece86f Mon Sep 17 00:00:00 2001
From: Felix Lange <fjl@twurst.com>
Date: Tue, 14 Oct 2014 14:33:58 +0200
Subject: [PATCH 03/15] ethlog: Reset before each test

---
 ethlog/loggers_test.go | 16 ++++++++++++----
 1 file changed, 12 insertions(+), 4 deletions(-)

diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go
index 2b0d1fb1d0..fbfb2c99b3 100644
--- a/ethlog/loggers_test.go
+++ b/ethlog/loggers_test.go
@@ -29,6 +29,8 @@ func (t *TestLogSystem) GetLogLevel() LogLevel {
 }
 
 func TestLoggerFlush(t *testing.T) {
+	Reset()
+
 	logger := NewLogger("TEST")
 	testLogSystem := &TestLogSystem{level: WarnLevel}
 	AddLogSystem(testLogSystem)
@@ -36,7 +38,6 @@ func TestLoggerFlush(t *testing.T) {
 		logger.Errorf(".")
 	}
 	Flush()
-	Reset()
 	output := testLogSystem.Output
 	if output != "[TEST] .[TEST] .[TEST] .[TEST] .[TEST] ." {
 		t.Error("Expected complete logger output '[TEST] .[TEST] .[TEST] .[TEST] .[TEST] .', got ", output)
@@ -44,6 +45,8 @@ func TestLoggerFlush(t *testing.T) {
 }
 
 func TestLoggerPrintln(t *testing.T) {
+	Reset()
+
 	logger := NewLogger("TEST")
 	testLogSystem := &TestLogSystem{level: WarnLevel}
 	AddLogSystem(testLogSystem)
@@ -52,7 +55,6 @@ func TestLoggerPrintln(t *testing.T) {
 	logger.Infoln("info")
 	logger.Debugln("debug")
 	Flush()
-	Reset()
 	output := testLogSystem.Output
 	if output != "[TEST] error\n[TEST] warn\n" {
 		t.Error("Expected logger output '[TEST] error\\n[TEST] warn\\n', got ", output)
@@ -60,6 +62,8 @@ func TestLoggerPrintln(t *testing.T) {
 }
 
 func TestLoggerPrintf(t *testing.T) {
+	Reset()
+
 	logger := NewLogger("TEST")
 	testLogSystem := &TestLogSystem{level: WarnLevel}
 	AddLogSystem(testLogSystem)
@@ -68,7 +72,6 @@ func TestLoggerPrintf(t *testing.T) {
 	logger.Infof("info")
 	logger.Debugf("debug")
 	Flush()
-	Reset()
 	output := testLogSystem.Output
 	if output != "[TEST] error to { 2}\n[TEST] warn" {
 		t.Error("Expected logger output '[TEST] error to { 2}\\n[TEST] warn', got ", output)
@@ -76,6 +79,8 @@ func TestLoggerPrintf(t *testing.T) {
 }
 
 func TestMultipleLogSystems(t *testing.T) {
+	Reset()
+
 	logger := NewLogger("TEST")
 	testLogSystem0 := &TestLogSystem{level: ErrorLevel}
 	testLogSystem1 := &TestLogSystem{level: WarnLevel}
@@ -84,7 +89,6 @@ func TestMultipleLogSystems(t *testing.T) {
 	logger.Errorln("error")
 	logger.Warnln("warn")
 	Flush()
-	Reset()
 	output0 := testLogSystem0.Output
 	output1 := testLogSystem1.Output
 	if output0 != "[TEST] error\n" {
@@ -96,6 +100,8 @@ func TestMultipleLogSystems(t *testing.T) {
 }
 
 func TestFileLogSystem(t *testing.T) {
+	Reset()
+
 	logger := NewLogger("TEST")
 	filename := "test.log"
 	file, _ := os.OpenFile(filename, os.O_RDWR|os.O_CREATE, os.ModePerm)
@@ -114,6 +120,8 @@ func TestFileLogSystem(t *testing.T) {
 }
 
 func TestNoLogSystem(t *testing.T) {
+	Reset()
+
 	logger := NewLogger("TEST")
 	logger.Warnln("warn")
 	Flush()

From d5a7ba1626b9c7bbc5733a44fbda2ed50070c1b9 Mon Sep 17 00:00:00 2001
From: Felix Lange <fjl@twurst.com>
Date: Tue, 14 Oct 2014 14:35:16 +0200
Subject: [PATCH 04/15] ethlog: add test that adds log systems concurrently

---
 ethlog/loggers_test.go | 29 +++++++++++++++++++++++++++++
 1 file changed, 29 insertions(+)

diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go
index fbfb2c99b3..4c62a0dbd5 100644
--- a/ethlog/loggers_test.go
+++ b/ethlog/loggers_test.go
@@ -3,8 +3,10 @@ package ethlog
 import (
 	"fmt"
 	"io/ioutil"
+	"math/rand"
 	"os"
 	"testing"
+	"time"
 )
 
 type TestLogSystem struct {
@@ -126,3 +128,30 @@ func TestNoLogSystem(t *testing.T) {
 	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.Infof("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(&TestLogSystem{level: InfoLevel})
+	}
+	close(stop)
+}

From 45d1052229f5390d76e912f15e17240a0eddc7b9 Mon Sep 17 00:00:00 2001
From: Felix Lange <fjl@twurst.com>
Date: Tue, 14 Oct 2014 14:35:54 +0200
Subject: [PATCH 05/15] ethlog: fix StdLogSystem data race on level

---
 ethlog/loggers.go | 9 +++++----
 1 file changed, 5 insertions(+), 4 deletions(-)

diff --git a/ethlog/loggers.go b/ethlog/loggers.go
index 34561853a9..edf77bda12 100644
--- a/ethlog/loggers.go
+++ b/ethlog/loggers.go
@@ -6,6 +6,7 @@ import (
 	"log"
 	"os"
 	"sync"
+	"sync/atomic"
 )
 
 type LogSystem interface {
@@ -198,7 +199,7 @@ func (logger *Logger) Fatalf(format string, v ...interface{}) {
 
 type StdLogSystem struct {
 	logger *log.Logger
-	level  LogLevel
+	level  uint32
 }
 
 func (t *StdLogSystem) Println(v ...interface{}) {
@@ -210,14 +211,14 @@ func (t *StdLogSystem) Printf(format string, v ...interface{}) {
 }
 
 func (t *StdLogSystem) SetLogLevel(i LogLevel) {
-	t.level = i
+	atomic.StoreUint32(&t.level, uint32(i))
 }
 
 func (t *StdLogSystem) GetLogLevel() LogLevel {
-	return t.level
+	return LogLevel(atomic.LoadUint32(&t.level))
 }
 
 func NewStdLogSystem(writer io.Writer, flags int, level LogLevel) *StdLogSystem {
 	logger := log.New(writer, "", flags)
-	return &StdLogSystem{logger, level}
+	return &StdLogSystem{logger, uint32(level)}
 }

From ec132749aab8f4b26181bfc2c4b3190aa104fdb5 Mon Sep 17 00:00:00 2001
From: Felix Lange <fjl@twurst.com>
Date: Tue, 14 Oct 2014 19:05:43 +0200
Subject: [PATCH 06/15] ethlog: improve TestLogSystem

It's now safe for concurrent access.
Output checking looks better.
---
 ethlog/loggers_test.go | 65 ++++++++++++++++++++++++------------------
 1 file changed, 38 insertions(+), 27 deletions(-)

diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go
index 4c62a0dbd5..c1a7de9978 100644
--- a/ethlog/loggers_test.go
+++ b/ethlog/loggers_test.go
@@ -5,29 +5,50 @@ import (
 	"io/ioutil"
 	"math/rand"
 	"os"
+	"sync"
 	"testing"
 	"time"
 )
 
 type TestLogSystem struct {
-	Output string
+	mutex  sync.Mutex
+	output string
 	level  LogLevel
 }
 
-func (t *TestLogSystem) Println(v ...interface{}) {
-	t.Output += fmt.Sprintln(v...)
+func (ls *TestLogSystem) Println(v ...interface{}) {
+	ls.mutex.Lock()
+	ls.output += fmt.Sprintln(v...)
+	ls.mutex.Unlock()
 }
 
-func (t *TestLogSystem) Printf(format string, v ...interface{}) {
-	t.Output += fmt.Sprintf(format, v...)
+func (ls *TestLogSystem) Printf(format string, v ...interface{}) {
+	ls.mutex.Lock()
+	ls.output += fmt.Sprintf(format, v...)
+	ls.mutex.Unlock()
 }
 
-func (t *TestLogSystem) SetLogLevel(i LogLevel) {
-	t.level = i
+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)
+	}
 }
 
-func (t *TestLogSystem) GetLogLevel() LogLevel {
-	return t.level
 }
 
 func TestLoggerFlush(t *testing.T) {
@@ -57,10 +78,8 @@ func TestLoggerPrintln(t *testing.T) {
 	logger.Infoln("info")
 	logger.Debugln("debug")
 	Flush()
-	output := testLogSystem.Output
-	if output != "[TEST] error\n[TEST] warn\n" {
-		t.Error("Expected logger output '[TEST] error\\n[TEST] warn\\n', got ", output)
-	}
+
+	testLogSystem.CheckOutput(t, "[TEST] error\n[TEST] warn\n")
 }
 
 func TestLoggerPrintf(t *testing.T) {
@@ -69,15 +88,12 @@ func TestLoggerPrintf(t *testing.T) {
 	logger := NewLogger("TEST")
 	testLogSystem := &TestLogSystem{level: WarnLevel}
 	AddLogSystem(testLogSystem)
-	logger.Errorf("error to %v\n", *testLogSystem)
+	logger.Errorf("error to %v\n", []int{1, 2, 3})
 	logger.Warnf("warn")
 	logger.Infof("info")
 	logger.Debugf("debug")
 	Flush()
-	output := testLogSystem.Output
-	if output != "[TEST] error to { 2}\n[TEST] warn" {
-		t.Error("Expected logger output '[TEST] error to { 2}\\n[TEST] warn', got ", output)
-	}
+	testLogSystem.CheckOutput(t, "[TEST] error to [1 2 3]\n[TEST] warn")
 }
 
 func TestMultipleLogSystems(t *testing.T) {
@@ -91,14 +107,9 @@ func TestMultipleLogSystems(t *testing.T) {
 	logger.Errorln("error")
 	logger.Warnln("warn")
 	Flush()
-	output0 := testLogSystem0.Output
-	output1 := testLogSystem1.Output
-	if output0 != "[TEST] error\n" {
-		t.Error("Expected logger 0 output '[TEST] error\\n', got ", output0)
-	}
-	if output1 != "[TEST] error\n[TEST] warn\n" {
-		t.Error("Expected logger 1 output '[TEST] error\\n[TEST] warn\\n', got ", output1)
-	}
+
+	testLogSystem0.CheckOutput(t, "[TEST] error\n")
+	testLogSystem1.CheckOutput(t, "[TEST] error\n[TEST] warn\n")
 }
 
 func TestFileLogSystem(t *testing.T) {
@@ -140,7 +151,7 @@ func TestConcurrentAddSystem(t *testing.T) {
 		case <-stop:
 			return
 		default:
-			logger.Infof("foo")
+			logger.Infoln("foo")
 			Flush()
 		}
 	}

From 793baf060a0e918b5d5ca72a425c99751b93ab41 Mon Sep 17 00:00:00 2001
From: Felix Lange <fjl@twurst.com>
Date: Tue, 14 Oct 2014 19:07:19 +0200
Subject: [PATCH 07/15] ethlog: don't buffer output in TestConcurrentAddSystem

---
 ethlog/loggers_test.go | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go
index c1a7de9978..ffc30e21f1 100644
--- a/ethlog/loggers_test.go
+++ b/ethlog/loggers_test.go
@@ -162,7 +162,7 @@ func TestConcurrentAddSystem(t *testing.T) {
 	stopTime := time.Now().Add(100 * time.Millisecond)
 	for time.Now().Before(stopTime) {
 		time.Sleep(time.Duration(rand.Intn(20)) * time.Millisecond)
-		AddLogSystem(&TestLogSystem{level: InfoLevel})
+		AddLogSystem(NewStdLogSystem(ioutil.Discard, 0, InfoLevel))
 	}
 	close(stop)
 }

From a6265cb49a0fd5641e53ed8cc8505bb91cb88976 Mon Sep 17 00:00:00 2001
From: Felix Lange <fjl@twurst.com>
Date: Tue, 14 Oct 2014 19:07:54 +0200
Subject: [PATCH 08/15] ethlog: verify that Flush is blocking in
 TestLoggerFlush

---
 ethlog/loggers_test.go | 30 ++++++++++++++++++++++++------
 1 file changed, 24 insertions(+), 6 deletions(-)

diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go
index ffc30e21f1..0466a3d599 100644
--- a/ethlog/loggers_test.go
+++ b/ethlog/loggers_test.go
@@ -49,22 +49,40 @@ func (ls *TestLogSystem) CheckOutput(t *testing.T, expected string) {
 	}
 }
 
+type blockedLogSystem struct {
+	LogSystem
+	unblock chan struct{}
+}
+
+func (ls blockedLogSystem) Println(v ...interface{}) {
+	<-ls.unblock
+	ls.LogSystem.Println(v...)
+}
+
+func (ls blockedLogSystem) Printf(fmt string, v ...interface{}) {
+	<-ls.unblock
+	ls.LogSystem.Printf(fmt, v...)
 }
 
 func TestLoggerFlush(t *testing.T) {
 	Reset()
 
 	logger := NewLogger("TEST")
-	testLogSystem := &TestLogSystem{level: WarnLevel}
-	AddLogSystem(testLogSystem)
+	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(".")
 	}
-	Flush()
-	output := testLogSystem.Output
-	if output != "[TEST] .[TEST] .[TEST] .[TEST] .[TEST] ." {
-		t.Error("Expected complete logger output '[TEST] .[TEST] .[TEST] .[TEST] .[TEST] .', got ", output)
+
+	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) {

From e0f93c74c54f04e8da18ee0f0eee58e322ddc89b Mon Sep 17 00:00:00 2001
From: Felix Lange <fjl@twurst.com>
Date: Tue, 14 Oct 2014 19:35:10 +0200
Subject: [PATCH 09/15] ethlog: add Godoc documentation, remove README

---
 ethlog/README.md  | 62 ---------------------------------
 ethlog/loggers.go | 87 ++++++++++++++++++++++++++++++++++++++---------
 2 files changed, 70 insertions(+), 79 deletions(-)
 delete mode 100644 ethlog/README.md

diff --git a/ethlog/README.md b/ethlog/README.md
deleted file mode 100644
index d9b69e1066..0000000000
--- a/ethlog/README.md
+++ /dev/null
@@ -1,62 +0,0 @@
-## Features
-
-- packages use tagged logger sending log messages to shared (process-wide) logging engine
-- log writers (interface ethlog.LogSystem) can be added to the logging engine by wrappers/guis/clients
-- shared logging engine dispatching to multiple log systems
-- log level can be set separately per log system
-- async logging thread: logging IO does not block main thread 
-- log messages are synchronously stringified to avoid incorrectly logging of changed states 
-- log level enum: ethlog.LogLevel:   Silence, ErrorLevel, WarnLevel, InfoLevel, DebugLevel, DebugDetailLevel
-
-## Usage
-
-In an ethereum component package:
-
-    import "github.com/ethereum/eth-go/ethlog"
-
-    // package-wide logger using tag
-    var logger = ethlog.NewLogger("TAG")
-
-Logger provides named Printf and Println style methods for all loglevels
-
-    logger.Infoln("this is info") # > [TAG] This is info
-    logger.Infof("this %v is info", object) # > [TAG] This object is info
-
-Ethereum wrappers should register log systems conforming to ethlog.LogSystem
-
-    import "github.com/ethereum/eth-go/ethlog"
-    
-    type CustomLogWriter struct {
-      logLevel ethlog.LogLevel
-    }
-
-    func (t *TestLogSystem) SetLogLevel(i LogLevel) {
-      t.level = i
-    }
-
-    func (t *TestLogSystem) GetLogLevel() LogLevel {
-      return t.level
-    }
-
-    func (c *CustomLogWriter) Printf(format string, v...interface{}) {
-      //....
-    }
-
-    func (c *CustomLogWriter) Println(v...interface{}) {
-      //....
-    }
-
-    ethlog.AddLogWriter(&CustomLogWriter{})
-
-ethlog also provides constructors for that wrap io.Writers into a standard logger with a settable level:
-
-    filename := "test.log"
-    file, _ := os.OpenFile(filename, os.O_RDWR|os.O_CREATE, os.ModePerm)
-    fileLogSystem := NewStdLogSystem(file, 0, WarnLevel)
-    AddLogSystem(fileLogSystem)
-    stdOutLogSystem := NewStdLogSystem(os.Stdout, 0, WarnLevel)
-    AddLogSystem(stdOutLogSystem)
-
-
-
-
diff --git a/ethlog/loggers.go b/ethlog/loggers.go
index edf77bda12..d1a4c58638 100644
--- a/ethlog/loggers.go
+++ b/ethlog/loggers.go
@@ -1,3 +1,36 @@
+/*
+Package ethlog implements a multi-output leveled logger.
+
+Features
+
+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 asynchrounous and does not block the main thread. Message
+formatting is performed by the caller goroutine to avoid incorrect
+logging of mutable state.
+
+Usage
+
+The Logger type provides named Printf and Println style methods for
+all loglevels. Each ethereum component should have its own logger with
+a unique prefix.
+
+    logger.Infoln("this is info") # > [TAG] This is info
+    logger.Infof("this %v is info", object) # > [TAG] This object is info
+
+ethlog also provides constructors for that wrap io.Writers into a
+standard logger with a settable level:
+
+    filename := "test.log"
+    file, _ := os.OpenFile(filename, os.O_RDWR|os.O_CREATE, os.ModePerm)
+    fileLogSystem := NewStdLogSystem(file, 0, WarnLevel)
+    AddLogSystem(fileLogSystem)
+    stdOutLogSystem := NewStdLogSystem(os.Stdout, 0, WarnLevel)
+    AddLogSystem(stdOutLogSystem)
+
+*/
 package ethlog
 
 import (
@@ -9,6 +42,8 @@ import (
 	"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)
@@ -33,6 +68,7 @@ func newPrintfLogMessage(level LogLevel, tag string, format string, v ...interfa
 type LogLevel uint8
 
 const (
+	// Standard log levels
 	Silence LogLevel = iota
 	ErrorLevel
 	WarnLevel
@@ -102,7 +138,7 @@ func send(msg *logMessage) {
 	logMessages <- msg
 }
 
-// Reset removes all registered log systems.
+// Reset removes all active log systems.
 func Reset() {
 	mutex.Lock()
 	logSystems = nil
@@ -117,6 +153,15 @@ func Flush() {
 	<-waiter
 }
 
+// AddLogSystem starts printing messages to the given LogSystem.
+func AddLogSystem(logSystem LogSystem) {
+	mutex.Lock()
+	logSystems = append(logSystems, logSystem)
+	mutex.Unlock()
+}
+
+// A Logger prints messages prefixed by a given tag.
+// You should create one with a unique tag for each high-level component.
 type Logger struct {
 	tag string
 }
@@ -125,12 +170,6 @@ func NewLogger(tag string) *Logger {
 	return &Logger{tag}
 }
 
-func AddLogSystem(logSystem LogSystem) {
-	mutex.Lock()
-	logSystems = append(logSystems, logSystem)
-	mutex.Unlock()
-}
-
 func (logger *Logger) sendln(level LogLevel, v ...interface{}) {
 	if logMessages != nil {
 		msg := newPrintlnLogMessage(level, logger.tag, v...)
@@ -145,80 +184,94 @@ func (logger *Logger) sendf(level LogLevel, format string, v ...interface{}) {
 	}
 }
 
+// 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)
 }
 
-type StdLogSystem struct {
+// 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) Println(v ...interface{}) {
+func (t *stdLogSystem) Println(v ...interface{}) {
 	t.logger.Println(v...)
 }
 
-func (t *StdLogSystem) Printf(format string, v ...interface{}) {
+func (t *stdLogSystem) Printf(format string, v ...interface{}) {
 	t.logger.Printf(format, v...)
 }
 
-func (t *StdLogSystem) SetLogLevel(i LogLevel) {
+func (t *stdLogSystem) SetLogLevel(i LogLevel) {
 	atomic.StoreUint32(&t.level, uint32(i))
 }
 
-func (t *StdLogSystem) GetLogLevel() LogLevel {
+func (t *stdLogSystem) GetLogLevel() LogLevel {
 	return LogLevel(atomic.LoadUint32(&t.level))
 }
-
-func NewStdLogSystem(writer io.Writer, flags int, level LogLevel) *StdLogSystem {
-	logger := log.New(writer, "", flags)
-	return &StdLogSystem{logger, uint32(level)}
-}

From 0165c1833017963a280f135a5733974a9fc3ec0b Mon Sep 17 00:00:00 2001
From: Felix Lange <fjl@twurst.com>
Date: Wed, 15 Oct 2014 11:15:59 +0200
Subject: [PATCH 10/15] ethlog: use Godoc for code examples in documentation

This ensures that examples will actually compile.
---
 ethlog/example_test.go | 21 +++++++++++++++++++++
 ethlog/loggers.go      | 36 ++++++++----------------------------
 2 files changed, 29 insertions(+), 28 deletions(-)
 create mode 100644 ethlog/example_test.go

diff --git a/ethlog/example_test.go b/ethlog/example_test.go
new file mode 100644
index 0000000000..2532f36c13
--- /dev/null
+++ b/ethlog/example_test.go
@@ -0,0 +1,21 @@
+package ethlog
+
+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/ethlog/loggers.go b/ethlog/loggers.go
index d1a4c58638..b8a7b04556 100644
--- a/ethlog/loggers.go
+++ b/ethlog/loggers.go
@@ -1,35 +1,14 @@
 /*
 Package ethlog implements a multi-output leveled logger.
 
-Features
+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.
 
-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 asynchrounous and does not block the main thread. Message
+Logging is asynchrounous and does not block the caller. Message
 formatting is performed by the caller goroutine to avoid incorrect
 logging of mutable state.
-
-Usage
-
-The Logger type provides named Printf and Println style methods for
-all loglevels. Each ethereum component should have its own logger with
-a unique prefix.
-
-    logger.Infoln("this is info") # > [TAG] This is info
-    logger.Infof("this %v is info", object) # > [TAG] This object is info
-
-ethlog also provides constructors for that wrap io.Writers into a
-standard logger with a settable level:
-
-    filename := "test.log"
-    file, _ := os.OpenFile(filename, os.O_RDWR|os.O_CREATE, os.ModePerm)
-    fileLogSystem := NewStdLogSystem(file, 0, WarnLevel)
-    AddLogSystem(fileLogSystem)
-    stdOutLogSystem := NewStdLogSystem(os.Stdout, 0, WarnLevel)
-    AddLogSystem(stdOutLogSystem)
-
 */
 package ethlog
 
@@ -160,8 +139,9 @@ func AddLogSystem(logSystem LogSystem) {
 	mutex.Unlock()
 }
 
-// A Logger prints messages prefixed by a given tag.
-// You should create one with a unique tag for each high-level component.
+// 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
 }

From cbd785cfe8801c240bbaaa6f21ebf3ab7045e4a3 Mon Sep 17 00:00:00 2001
From: Felix Lange <fjl@twurst.com>
Date: Thu, 16 Oct 2014 10:47:12 +0200
Subject: [PATCH 11/15] ethvm, tests/*: use log level constants

---
 ethvm/vm_test.go     | 14 +++++++-------
 tests/helper/init.go |  2 +-
 tests/vm/gh_test.go  |  4 ++++
 3 files changed, 12 insertions(+), 8 deletions(-)

diff --git a/ethvm/vm_test.go b/ethvm/vm_test.go
index c210088364..6b7cc2f5c1 100644
--- a/ethvm/vm_test.go
+++ b/ethvm/vm_test.go
@@ -39,14 +39,14 @@ for i := 0; i < 10; i++ {
 
 return x`
 
-func setup(level int, typ Type) (*Closure, VirtualMachine) {
+func setup(level ethlog.LogLevel, typ Type) (*Closure, VirtualMachine) {
 	code, err := ethutil.Compile(mutcode, true)
 	if err != nil {
 		log.Fatal(err)
 	}
 
 	// Pipe output to /dev/null
-	ethlog.AddLogSystem(ethlog.NewStdLogSystem(ioutil.Discard, log.LstdFlags, ethlog.LogLevel(level)))
+	ethlog.AddLogSystem(ethlog.NewStdLogSystem(ioutil.Discard, log.LstdFlags, level))
 
 	ethutil.ReadConfig(".ethtest", "/tmp/ethtest", "")
 
@@ -57,7 +57,7 @@ func setup(level int, typ Type) (*Closure, VirtualMachine) {
 }
 
 func TestDebugVm(t *testing.T) {
-	closure, vm := setup(4, DebugVmTy)
+	closure, vm := setup(ethlog.DebugLevel, DebugVmTy)
 	ret, _, e := closure.Call(vm, nil)
 	if e != nil {
 		fmt.Println("error", e)
@@ -69,7 +69,7 @@ func TestDebugVm(t *testing.T) {
 }
 
 func TestVm(t *testing.T) {
-	closure, vm := setup(4, StandardVmTy)
+	closure, vm := setup(ethlog.DebugLevel, StandardVmTy)
 	ret, _, e := closure.Call(vm, nil)
 	if e != nil {
 		fmt.Println("error", e)
@@ -81,7 +81,7 @@ func TestVm(t *testing.T) {
 }
 
 func BenchmarkDebugVm(b *testing.B) {
-	closure, vm := setup(3, DebugVmTy)
+	closure, vm := setup(ethlog.InfoLevel, DebugVmTy)
 
 	b.ResetTimer()
 
@@ -91,7 +91,7 @@ func BenchmarkDebugVm(b *testing.B) {
 }
 
 func BenchmarkVm(b *testing.B) {
-	closure, vm := setup(3, StandardVmTy)
+	closure, vm := setup(ethlog.InfoLevel, StandardVmTy)
 
 	b.ResetTimer()
 
@@ -106,7 +106,7 @@ func RunCode(mutCode string, typ Type) []byte {
 		log.Fatal(err)
 	}
 
-	ethlog.AddLogSystem(ethlog.NewStdLogSystem(os.Stdout, log.LstdFlags, ethlog.LogLevel(3)))
+	ethlog.AddLogSystem(ethlog.NewStdLogSystem(os.Stdout, log.LstdFlags, ethlog.InfoLevel))
 
 	ethutil.ReadConfig(".ethtest", "/tmp/ethtest", "")
 
diff --git a/tests/helper/init.go b/tests/helper/init.go
index a84a7749f9..3de5c50ebb 100644
--- a/tests/helper/init.go
+++ b/tests/helper/init.go
@@ -12,7 +12,7 @@ var Logger ethlog.LogSystem
 var Log = ethlog.NewLogger("TEST")
 
 func init() {
-	Logger = ethlog.NewStdLogSystem(os.Stdout, log.LstdFlags, ethlog.LogLevel(3))
+	Logger = ethlog.NewStdLogSystem(os.Stdout, log.LstdFlags, ethlog.InfoLevel)
 	ethlog.AddLogSystem(Logger)
 
 	ethutil.ReadConfig(".ethtest", "/tmp/ethtest", "")
diff --git a/tests/vm/gh_test.go b/tests/vm/gh_test.go
index 5de5b64330..0e0c6aa490 100644
--- a/tests/vm/gh_test.go
+++ b/tests/vm/gh_test.go
@@ -4,6 +4,7 @@ import (
 	"bytes"
 	"testing"
 
+	"github.com/ethereum/eth-go/ethlog"
 	"github.com/ethereum/eth-go/ethstate"
 	"github.com/ethereum/eth-go/ethutil"
 	"github.com/ethereum/eth-go/tests/helper"
@@ -87,6 +88,9 @@ func RunVmTest(url string, t *testing.T) {
 }
 
 // I've created a new function for each tests so it's easier to identify where the problem lies if any of them fail.
+func TestVMSha3(t *testing.T) {
+	helper.Logger.SetLogLevel(ethlog.Silence)
+	defer helper.Logger.SetLogLevel(ethlog.DebugLevel)
 
 func TestVMArithmetic(t *testing.T) {
 	const url = "https://raw.githubusercontent.com/ethereum/tests/develop/vmtests/vmArithmeticTest.json"

From 50f5ba5b0cfdf02cd87a9070676bd3c21c217296 Mon Sep 17 00:00:00 2001
From: Felix Lange <fjl@twurst.com>
Date: Thu, 16 Oct 2014 10:48:33 +0200
Subject: [PATCH 12/15] ethlog: add test for '%' in log message

This test fails because the log message is formatted twice.
---
 ethlog/loggers_test.go | 4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go
index 0466a3d599..23f649312c 100644
--- a/ethlog/loggers_test.go
+++ b/ethlog/loggers_test.go
@@ -107,11 +107,11 @@ func TestLoggerPrintf(t *testing.T) {
 	testLogSystem := &TestLogSystem{level: WarnLevel}
 	AddLogSystem(testLogSystem)
 	logger.Errorf("error to %v\n", []int{1, 2, 3})
-	logger.Warnf("warn")
+	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")
+	testLogSystem.CheckOutput(t, "[TEST] error to [1 2 3]\n[TEST] warn %d 5")
 }
 
 func TestMultipleLogSystems(t *testing.T) {

From c090a77f1c9bc890e67a00fb47a1c23c8769799d Mon Sep 17 00:00:00 2001
From: Felix Lange <fjl@twurst.com>
Date: Thu, 16 Oct 2014 10:50:51 +0200
Subject: [PATCH 13/15] ethlog: simplify LogSystem interface

Messages are formatted by generic part, so the log system doesn't need
to provide formatting. This fixes the test from the previous commit.

As a small bonus, log systems now have access to the level of
the message. This could be used to provide colored logging in the
future.
---
 ethlog/loggers.go      | 57 ++++++++++--------------------------------
 ethlog/loggers_test.go | 20 +++------------
 2 files changed, 17 insertions(+), 60 deletions(-)

diff --git a/ethlog/loggers.go b/ethlog/loggers.go
index b8a7b04556..f5ec4d4029 100644
--- a/ethlog/loggers.go
+++ b/ethlog/loggers.go
@@ -26,22 +26,12 @@ import (
 type LogSystem interface {
 	GetLogLevel() LogLevel
 	SetLogLevel(i LogLevel)
-	Println(v ...interface{})
-	Printf(format string, v ...interface{})
+	LogPrint(LogLevel, string)
 }
 
-type logMessage struct {
-	LogLevel LogLevel
-	format   bool
-	msg      string
-}
-
-func newPrintlnLogMessage(level LogLevel, tag string, v ...interface{}) *logMessage {
-	return &logMessage{level, false, fmt.Sprintf("[%s] %s", tag, fmt.Sprint(v...))}
-}
-
-func newPrintfLogMessage(level LogLevel, tag string, format string, v ...interface{}) *logMessage {
-	return &logMessage{level, true, fmt.Sprintf("[%s] %s", tag, fmt.Sprintf(format, v...))}
+type message struct {
+	level LogLevel
+	msg   string
 }
 
 type LogLevel uint8
@@ -60,7 +50,7 @@ var (
 	mutex      sync.RWMutex // protects logSystems
 	logSystems []LogSystem
 
-	logMessages  = make(chan *logMessage)
+	logMessages  = make(chan message)
 	drainWaitReq = make(chan chan struct{})
 )
 
@@ -95,28 +85,17 @@ func dispatchLoop() {
 	}
 }
 
-func dispatch(msg *logMessage, done chan<- struct{}) {
+func dispatch(msg message, done chan<- struct{}) {
 	mutex.RLock()
 	for _, sys := range logSystems {
-		if sys.GetLogLevel() >= msg.LogLevel {
-			if msg.format {
-				sys.Printf(msg.msg)
-			} else {
-				sys.Println(msg.msg)
-			}
+		if sys.GetLogLevel() >= msg.level {
+			sys.LogPrint(msg.level, msg.msg)
 		}
 	}
 	mutex.RUnlock()
 	done <- struct{}{}
 }
 
-// send delivers a message to all installed log
-// systems. it doesn't wait for the message to be
-// written.
-func send(msg *logMessage) {
-	logMessages <- msg
-}
-
 // Reset removes all active log systems.
 func Reset() {
 	mutex.Lock()
@@ -147,21 +126,15 @@ type Logger struct {
 }
 
 func NewLogger(tag string) *Logger {
-	return &Logger{tag}
+	return &Logger{"[" + tag + "] "}
 }
 
 func (logger *Logger) sendln(level LogLevel, v ...interface{}) {
-	if logMessages != nil {
-		msg := newPrintlnLogMessage(level, logger.tag, v...)
-		send(msg)
-	}
+	logMessages <- message{level, logger.tag + fmt.Sprintln(v...)}
 }
 
 func (logger *Logger) sendf(level LogLevel, format string, v ...interface{}) {
-	if logMessages != nil {
-		msg := newPrintfLogMessage(level, logger.tag, format, v...)
-		send(msg)
-	}
+	logMessages <- message{level, logger.tag + fmt.Sprintf(format, v...)}
 }
 
 // Errorln writes a message with ErrorLevel.
@@ -240,12 +213,8 @@ type stdLogSystem struct {
 	level  uint32
 }
 
-func (t *stdLogSystem) Println(v ...interface{}) {
-	t.logger.Println(v...)
-}
-
-func (t *stdLogSystem) Printf(format string, v ...interface{}) {
-	t.logger.Printf(format, v...)
+func (t *stdLogSystem) LogPrint(level LogLevel, msg string) {
+	t.logger.Print(msg)
 }
 
 func (t *stdLogSystem) SetLogLevel(i LogLevel) {
diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go
index 23f649312c..cf92e3cc66 100644
--- a/ethlog/loggers_test.go
+++ b/ethlog/loggers_test.go
@@ -1,7 +1,6 @@
 package ethlog
 
 import (
-	"fmt"
 	"io/ioutil"
 	"math/rand"
 	"os"
@@ -16,15 +15,9 @@ type TestLogSystem struct {
 	level  LogLevel
 }
 
-func (ls *TestLogSystem) Println(v ...interface{}) {
+func (ls *TestLogSystem) LogPrint(level LogLevel, msg string) {
 	ls.mutex.Lock()
-	ls.output += fmt.Sprintln(v...)
-	ls.mutex.Unlock()
-}
-
-func (ls *TestLogSystem) Printf(format string, v ...interface{}) {
-	ls.mutex.Lock()
-	ls.output += fmt.Sprintf(format, v...)
+	ls.output += msg
 	ls.mutex.Unlock()
 }
 
@@ -54,14 +47,9 @@ type blockedLogSystem struct {
 	unblock chan struct{}
 }
 
-func (ls blockedLogSystem) Println(v ...interface{}) {
-	<-ls.unblock
-	ls.LogSystem.Println(v...)
-}
-
-func (ls blockedLogSystem) Printf(fmt string, v ...interface{}) {
+func (ls blockedLogSystem) LogPrint(level LogLevel, msg string) {
 	<-ls.unblock
-	ls.LogSystem.Printf(fmt, v...)
+	ls.LogSystem.LogPrint(level, msg)
 }
 
 func TestLoggerFlush(t *testing.T) {

From fd9b03a431a9b8bb28a5b681f97e0b2d18ef7a3e Mon Sep 17 00:00:00 2001
From: Felix Lange <fjl@twurst.com>
Date: Thu, 16 Oct 2014 11:50:10 +0200
Subject: [PATCH 14/15] ethlog: fix concurrency

Rather than spawning a new goroutine for each message,
run each log system in a dedicated goroutine.

Ensure that logging is still asynchronous by using a per-system buffer
(currently 500 messages). If it overflows all logging will hang,
but that's better than spawning indefinitely many goroutines.
---
 ethlog/loggers.go | 98 +++++++++++++++++++++++++++++------------------
 1 file changed, 60 insertions(+), 38 deletions(-)

diff --git a/ethlog/loggers.go b/ethlog/loggers.go
index f5ec4d4029..732d6a970f 100644
--- a/ethlog/loggers.go
+++ b/ethlog/loggers.go
@@ -47,75 +47,97 @@ const (
 )
 
 var (
-	mutex      sync.RWMutex // protects logSystems
-	logSystems []LogSystem
-
-	logMessages  = make(chan message)
-	drainWaitReq = make(chan chan struct{})
+	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 drainWait []chan struct{}
-	dispatchDone := make(chan struct{})
-	pending := 0
+	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 := <-logMessages:
-			go dispatch(msg, dispatchDone)
-			pending++
-		case waiter := <-drainWaitReq:
-			if pending == 0 {
-				close(waiter)
-			} else {
-				drainWait = append(drainWait, waiter)
+		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)
 			}
-		case <-dispatchDone:
-			pending--
-			if pending == 0 {
-				for _, c := range drainWait {
-					close(c)
-				}
-				drainWait = nil
+			systemIn = nil
+			systemWG.Wait()
+			for _, sys := range systems {
+				bootSystem(sys)
 			}
+			close(waiter)
 		}
 	}
 }
 
-func dispatch(msg message, done chan<- struct{}) {
-	mutex.RLock()
-	for _, sys := range logSystems {
+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)
 		}
 	}
-	mutex.RUnlock()
-	done <- struct{}{}
+	wg.Done()
 }
 
 // Reset removes all active log systems.
+// It blocks until all current messages have been delivered.
 func Reset() {
-	mutex.Lock()
-	logSystems = nil
-	mutex.Unlock()
+	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{})
-	drainWaitReq <- waiter
+	flushC <- waiter
 	<-waiter
 }
 
 // AddLogSystem starts printing messages to the given LogSystem.
-func AddLogSystem(logSystem LogSystem) {
-	mutex.Lock()
-	logSystems = append(logSystems, logSystem)
-	mutex.Unlock()
+func AddLogSystem(sys LogSystem) {
+	addSystemC <- sys
 }
 
 // A Logger prints messages prefixed by a given tag. It provides named
@@ -130,11 +152,11 @@ func NewLogger(tag string) *Logger {
 }
 
 func (logger *Logger) sendln(level LogLevel, v ...interface{}) {
-	logMessages <- message{level, logger.tag + fmt.Sprintln(v...)}
+	logMessageC <- message{level, logger.tag + fmt.Sprintln(v...)}
 }
 
 func (logger *Logger) sendf(level LogLevel, format string, v ...interface{}) {
-	logMessages <- message{level, logger.tag + fmt.Sprintf(format, v...)}
+	logMessageC <- message{level, logger.tag + fmt.Sprintf(format, v...)}
 }
 
 // Errorln writes a message with ErrorLevel.

From 35f339e9423bb3f3b5130e954e4a03937971b0ac Mon Sep 17 00:00:00 2001
From: Felix Lange <fjl@twurst.com>
Date: Thu, 16 Oct 2014 12:11:17 +0200
Subject: [PATCH 15/15] ethlog: fix typo in documentation

---
 ethlog/loggers.go | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/ethlog/loggers.go b/ethlog/loggers.go
index 732d6a970f..986bb17597 100644
--- a/ethlog/loggers.go
+++ b/ethlog/loggers.go
@@ -6,7 +6,7 @@ Other packages use tagged logger to send log messages to shared
 multiple log systems. The log level can be set separately per log
 system.
 
-Logging is asynchrounous and does not block the caller. Message
+Logging is asynchronous and does not block the caller. Message
 formatting is performed by the caller goroutine to avoid incorrect
 logging of mutable state.
 */