logger fix

- introduce quit, drained, shutdown channels
- mainLoop falls through reading message channel to drained state, and waits is blocked in default branch until any message is sent
- Flush() waits for <-drained
- Stop() pushes quit and nodges mainloop out of blocking drained state
- package-global mutex
- Reset()
- clear tests

ethlog/loggers.go

@@ -40,6 +40,9 @@ func (msg *logMessage) send(logger LogSystem) {
 var logMessages chan (*logMessage)
 var logSystems []LogSystem
 var quit chan bool
+var drained chan bool
+var shutdown chan bool
+var mutex = sync.Mutex{}
 
 type LogLevel uint8
 
@@ -57,29 +60,41 @@ func start() {
 out:
 	for {
 		select {
+		case <-quit:
+			break out
 		case msg := <-logMessages:
 			for _, logSystem := range logSystems {
 				if logSystem.GetLogLevel() >= msg.LogLevel {
 					msg.send(logSystem)
 				}
 			}
-		case <-quit:
-			break out
+		case drained <- true:
+		default:
+			drained <- true // this blocks until a message is sent to the queu
 		}
 	}
+	close(shutdown)
 }
 
-// waits until log messages are drained (dispatched to log writers)
-func Flush() {
+func Reset() {
+	mutex.Lock()
+	defer mutex.Unlock()
+	if logSystems != nil {
 		quit <- true
-
-done:
-	for {
 		select {
-		case <-logMessages:
-		default:
-			break done
+		case <-drained:
+		}
+		<-shutdown
 	}
+	logSystems = nil
+}
+
+// waits until log messages are drained (dispatched to log writers)
+func Flush() {
+	mutex.Lock()
+	defer mutex.Unlock()
+	if logSystems != nil {
+		<-drained
 	}
 }
 
@@ -92,28 +107,34 @@ 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)
 		quit = make(chan bool)
+		drained = make(chan bool, 1)
+		shutdown = make(chan bool, 1)
 		go start()
 	}
 	logSystems = append(logSystems, logSystem)
 }
 
-func (logger *Logger) sendln(level LogLevel, v ...interface{}) {
-	if logMessages != nil {
-		msg := newPrintlnLogMessage(level, logger.tag, v...)
+func send(msg *logMessage) {
+	select {
+	case <-drained:
+	}
 	logMessages <- msg
 }
+
+func (logger *Logger) sendln(level LogLevel, v ...interface{}) {
+	if logSystems != nil {
+		send(newPrintlnLogMessage(level, logger.tag, v...))
+	}
 }
 
 func (logger *Logger) sendf(level LogLevel, format string, v ...interface{}) {
-	if logMessages != nil {
-		msg := newPrintfLogMessage(level, logger.tag, format, v...)
-		logMessages <- msg
+	if logSystems != nil {
+		send(newPrintfLogMessage(level, logger.tag, format, v...))
 	}
 }
 

ethlog/loggers_test.go

@@ -28,10 +28,6 @@ func (t *TestLogSystem) GetLogLevel() LogLevel {
 	return t.level
 }
 
-func quote(s string) string {
-	return fmt.Sprintf("'%s'", s)
-}
-
 func TestLoggerPrintln(t *testing.T) {
 	logger := NewLogger("TEST")
 	testLogSystem := &TestLogSystem{level: WarnLevel}
@@ -41,10 +37,10 @@ func TestLoggerPrintln(t *testing.T) {
 	logger.Infoln("info")
 	logger.Debugln("debug")
 	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 ", quote(testLogSystem.Output))
+		t.Error("Expected logger output '[TEST] error\\n[TEST] warn\\n', got ", testLogSystem.Output)
 	}
 }
 
@@ -57,10 +53,10 @@ func TestLoggerPrintf(t *testing.T) {
 	logger.Infof("info")
 	logger.Debugf("debug")
 	Flush()
+	Reset()
 	output := testLogSystem.Output
-	fmt.Println(quote(output))
 	if output != "[TEST] error to { 2}\n[TEST] warn" {
-		t.Error("Expected logger output '[TEST] error to { 2}\\n[TEST] warn', got ", quote(testLogSystem.Output))
+		t.Error("Expected logger output '[TEST] error to { 2}\\n[TEST] warn', got ", testLogSystem.Output)
 	}
 }
 
@@ -73,13 +69,14 @@ func TestMultipleLogSystems(t *testing.T) {
 	logger.Errorln("error")
 	logger.Warnln("warn")
 	Flush()
+	Reset()
 	output0 := testLogSystem0.Output
 	output1 := testLogSystem1.Output
 	if output0 != "[TEST] error\n" {
-		t.Error("Expected logger 0 output '[TEST] error\\n', got ", quote(testLogSystem0.Output))
+		t.Error("Expected logger 0 output '[TEST] error\\n', got ", testLogSystem0.Output)
 	}
 	if output1 != "[TEST] error\n[TEST] warn\n" {
-		t.Error("Expected logger 1 output '[TEST] error\\n[TEST] warn\\n', got ", quote(testLogSystem1.Output))
+		t.Error("Expected logger 1 output '[TEST] error\\n[TEST] warn\\n', got ", testLogSystem1.Output)
 	}
 }
 
@@ -92,11 +89,11 @@ func TestFileLogSystem(t *testing.T) {
 	logger.Errorf("error to %s\n", filename)
 	logger.Warnln("warn")
 	Flush()
+	Reset()
 	contents, _ := ioutil.ReadFile(filename)
 	output := string(contents)
-	fmt.Println(quote(output))
 	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 ", quote(output))
+		t.Error("Expected contents of file 'test.log': '[TEST] error to test.log\\n[TEST] warn\\n', got ", output)
 	} else {
 		os.Remove(filename)
 	}
@@ -105,5 +102,7 @@ func TestFileLogSystem(t *testing.T) {
 func TestNoLogSystem(t *testing.T) {
 	logger := NewLogger("TEST")
 	logger.Warnln("warn")
+	fmt.Println("1")
 	Flush()
+	Reset()
 }