From 8e9cc3697944c3e568186a5c23ac729f6eb4a1f4 Mon Sep 17 00:00:00 2001 From: zelig Date: Mon, 23 Jun 2014 12:49:04 +0100 Subject: refactor logging. Details: - 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 - README.md - loggers_test --- ethlog/loggers_test.go | 115 +++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 115 insertions(+) create mode 100644 ethlog/loggers_test.go (limited to 'ethlog/loggers_test.go') diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go new file mode 100644 index 000000000..c33082012 --- /dev/null +++ b/ethlog/loggers_test.go @@ -0,0 +1,115 @@ +package ethlog + +import ( + "testing" + "fmt" + "io/ioutil" + "os" +) + +type TestLogSystem struct { + Output string + level LogLevel +} + +func (t *TestLogSystem) Println(v ...interface{}) { + t.Output += fmt.Sprintln(v...) +} + +func (t *TestLogSystem) Printf(format string, v ...interface{}) { + t.Output += fmt.Sprintf(format, v...) +} + +func (t *TestLogSystem) SetLogLevel(i LogLevel) { + t.level = i +} + +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} + AddLogSystem(testLogSystem) + logger.Errorln("error") + logger.Warnln("warn") + logger.Infoln("info") + logger.Debugln("debug") + Flush() + 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)) + } +} + +func TestLoggerPrintf(t *testing.T) { + logger := NewLogger("TEST") + testLogSystem := &TestLogSystem{level: WarnLevel} + AddLogSystem(testLogSystem) + logger.Errorf("error to %v\n", *testLogSystem) + logger.Warnf("warn") + logger.Infof("info") + logger.Debugf("debug") + Flush() + 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)) + } +} + +func TestMultipleLogSystems(t *testing.T) { + logger := NewLogger("TEST") + testLogSystem0 := &TestLogSystem{level: ErrorLevel} + testLogSystem1 := &TestLogSystem{level: WarnLevel} + AddLogSystem(testLogSystem0) + AddLogSystem(testLogSystem1) + 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 ", quote(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)) + } +} + +func TestFileLogSystem(t *testing.T) { + 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) + 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)) + } else { + os.Remove(filename) + } +} + +func TestNoLogSystem(t *testing.T) { + logger := NewLogger("TEST") + logger.Warnln("warn") + Flush() +} + + + + + + -- cgit v1.2.3 From 853053a3b204ddf4ae935e70e0aa5b5d8994493e Mon Sep 17 00:00:00 2001 From: zelig Date: Thu, 26 Jun 2014 18:45:57 +0100 Subject: go fmt --- ethlog/loggers_test.go | 150 ++++++++++++++++++++++++------------------------- 1 file changed, 72 insertions(+), 78 deletions(-) (limited to 'ethlog/loggers_test.go') diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go index c33082012..89f416681 100644 --- a/ethlog/loggers_test.go +++ b/ethlog/loggers_test.go @@ -1,115 +1,109 @@ package ethlog import ( - "testing" - "fmt" - "io/ioutil" - "os" + "fmt" + "io/ioutil" + "os" + "testing" ) type TestLogSystem struct { - Output string - level LogLevel + Output string + level LogLevel } func (t *TestLogSystem) Println(v ...interface{}) { - t.Output += fmt.Sprintln(v...) + t.Output += fmt.Sprintln(v...) } func (t *TestLogSystem) Printf(format string, v ...interface{}) { - t.Output += fmt.Sprintf(format, v...) + t.Output += fmt.Sprintf(format, v...) } func (t *TestLogSystem) SetLogLevel(i LogLevel) { - t.level = i + t.level = i } func (t *TestLogSystem) GetLogLevel() LogLevel { - return t.level + return t.level } func quote(s string) string { - return fmt.Sprintf("'%s'", s) + return fmt.Sprintf("'%s'", s) } func TestLoggerPrintln(t *testing.T) { - logger := NewLogger("TEST") - testLogSystem := &TestLogSystem{level: WarnLevel} - AddLogSystem(testLogSystem) - logger.Errorln("error") - logger.Warnln("warn") - logger.Infoln("info") - logger.Debugln("debug") - Flush() - 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)) - } + logger := NewLogger("TEST") + testLogSystem := &TestLogSystem{level: WarnLevel} + AddLogSystem(testLogSystem) + logger.Errorln("error") + logger.Warnln("warn") + logger.Infoln("info") + logger.Debugln("debug") + Flush() + 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)) + } } func TestLoggerPrintf(t *testing.T) { - logger := NewLogger("TEST") - testLogSystem := &TestLogSystem{level: WarnLevel} - AddLogSystem(testLogSystem) - logger.Errorf("error to %v\n", *testLogSystem) - logger.Warnf("warn") - logger.Infof("info") - logger.Debugf("debug") - Flush() - 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)) - } + logger := NewLogger("TEST") + testLogSystem := &TestLogSystem{level: WarnLevel} + AddLogSystem(testLogSystem) + logger.Errorf("error to %v\n", *testLogSystem) + logger.Warnf("warn") + logger.Infof("info") + logger.Debugf("debug") + Flush() + 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)) + } } func TestMultipleLogSystems(t *testing.T) { - logger := NewLogger("TEST") - testLogSystem0 := &TestLogSystem{level: ErrorLevel} - testLogSystem1 := &TestLogSystem{level: WarnLevel} - AddLogSystem(testLogSystem0) - AddLogSystem(testLogSystem1) - 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 ", quote(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)) - } + logger := NewLogger("TEST") + testLogSystem0 := &TestLogSystem{level: ErrorLevel} + testLogSystem1 := &TestLogSystem{level: WarnLevel} + AddLogSystem(testLogSystem0) + AddLogSystem(testLogSystem1) + 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 ", quote(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)) + } } func TestFileLogSystem(t *testing.T) { - 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) - 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)) - } else { - os.Remove(filename) - } + 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) + 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)) + } else { + os.Remove(filename) + } } func TestNoLogSystem(t *testing.T) { - logger := NewLogger("TEST") - logger.Warnln("warn") - Flush() + logger := NewLogger("TEST") + logger.Warnln("warn") + Flush() } - - - - - - -- cgit v1.2.3 From d4300c406c5f98d35857b6e53b0427be5f45e3b2 Mon Sep 17 00:00:00 2001 From: zelig Date: Sat, 5 Jul 2014 18:36:22 +0100 Subject: 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_test.go | 23 +++++++++++------------ 1 file changed, 11 insertions(+), 12 deletions(-) (limited to 'ethlog/loggers_test.go') diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go index 89f416681..9fff471c1 100644 --- a/ethlog/loggers_test.go +++ b/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() } -- cgit v1.2.3 From 6fe9b4ab5e839be96eb1c4a619bc14fab622d8d1 Mon Sep 17 00:00:00 2001 From: Jeffrey Wilcke Date: Mon, 7 Jul 2014 10:59:16 +0200 Subject: Revert "ethreact - Feature/ethutil refactor" --- ethlog/loggers_test.go | 23 ++++++++++++----------- 1 file changed, 12 insertions(+), 11 deletions(-) (limited to 'ethlog/loggers_test.go') diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go index 9fff471c1..89f416681 100644 --- a/ethlog/loggers_test.go +++ b/ethlog/loggers_test.go @@ -28,6 +28,10 @@ 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} @@ -37,10 +41,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 ", testLogSystem.Output) + t.Error("Expected logger output '[TEST] error\\n[TEST] warn\\n', got ", quote(testLogSystem.Output)) } } @@ -53,10 +57,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 ", testLogSystem.Output) + t.Error("Expected logger output '[TEST] error to { 2}\\n[TEST] warn', got ", quote(testLogSystem.Output)) } } @@ -69,14 +73,13 @@ 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 ", testLogSystem0.Output) + t.Error("Expected logger 0 output '[TEST] error\\n', got ", quote(testLogSystem0.Output)) } if output1 != "[TEST] error\n[TEST] warn\n" { - t.Error("Expected logger 1 output '[TEST] error\\n[TEST] warn\\n', got ", testLogSystem1.Output) + t.Error("Expected logger 1 output '[TEST] error\\n[TEST] warn\\n', got ", quote(testLogSystem1.Output)) } } @@ -89,11 +92,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 ", output) + t.Error("Expected contents of file 'test.log': '[TEST] error to test.log\\n[TEST] warn\\n', got ", quote(output)) } else { os.Remove(filename) } @@ -102,7 +105,5 @@ func TestFileLogSystem(t *testing.T) { func TestNoLogSystem(t *testing.T) { logger := NewLogger("TEST") logger.Warnln("warn") - fmt.Println("1") Flush() - Reset() } -- cgit v1.2.3 From 5c03adbdededd31cb73f64ced01e33154347e193 Mon Sep 17 00:00:00 2001 From: zelig Date: Mon, 14 Jul 2014 18:37:01 +0100 Subject: fix logger channel blocking --- ethlog/loggers_test.go | 15 +++++++++++++++ 1 file changed, 15 insertions(+) (limited to 'ethlog/loggers_test.go') diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go index 9fff471c1..0e1c12e55 100644 --- a/ethlog/loggers_test.go +++ b/ethlog/loggers_test.go @@ -28,6 +28,21 @@ func (t *TestLogSystem) GetLogLevel() LogLevel { return t.level } +func TestLoggerFlush(t *testing.T) { + logger := NewLogger("TEST") + testLogSystem := &TestLogSystem{level: WarnLevel} + AddLogSystem(testLogSystem) + for i := 0; i < 5; i++ { + 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) + } +} + func TestLoggerPrintln(t *testing.T) { logger := NewLogger("TEST") testLogSystem := &TestLogSystem{level: WarnLevel} -- cgit v1.2.3 From dac128a029ee8d80d4ebdad64b24506c03d55e63 Mon Sep 17 00:00:00 2001 From: Felix Lange Date: Tue, 14 Oct 2014 14:31:33 +0200 Subject: ethlog: fix test compilation error --- ethlog/loggers_test.go | 1 - 1 file changed, 1 deletion(-) (limited to 'ethlog/loggers_test.go') diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go index a9b1463e7..2b0d1fb1d 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) } -- cgit v1.2.3 From 3b1296077b2f814bf4bf478aea63503d18ece86f Mon Sep 17 00:00:00 2001 From: Felix Lange Date: Tue, 14 Oct 2014 14:33:58 +0200 Subject: ethlog: Reset before each test --- ethlog/loggers_test.go | 16 ++++++++++++---- 1 file changed, 12 insertions(+), 4 deletions(-) (limited to 'ethlog/loggers_test.go') diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go index 2b0d1fb1d..fbfb2c99b 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() -- cgit v1.2.3 From d5a7ba1626b9c7bbc5733a44fbda2ed50070c1b9 Mon Sep 17 00:00:00 2001 From: Felix Lange Date: Tue, 14 Oct 2014 14:35:16 +0200 Subject: ethlog: add test that adds log systems concurrently --- ethlog/loggers_test.go | 29 +++++++++++++++++++++++++++++ 1 file changed, 29 insertions(+) (limited to 'ethlog/loggers_test.go') diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go index fbfb2c99b..4c62a0dbd 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) +} -- cgit v1.2.3 From ec132749aab8f4b26181bfc2c4b3190aa104fdb5 Mon Sep 17 00:00:00 2001 From: Felix Lange Date: Tue, 14 Oct 2014 19:05:43 +0200 Subject: 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(-) (limited to 'ethlog/loggers_test.go') diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go index 4c62a0dbd..c1a7de997 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() } } -- cgit v1.2.3 From 793baf060a0e918b5d5ca72a425c99751b93ab41 Mon Sep 17 00:00:00 2001 From: Felix Lange Date: Tue, 14 Oct 2014 19:07:19 +0200 Subject: ethlog: don't buffer output in TestConcurrentAddSystem --- ethlog/loggers_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) (limited to 'ethlog/loggers_test.go') diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go index c1a7de997..ffc30e21f 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) } -- cgit v1.2.3 From a6265cb49a0fd5641e53ed8cc8505bb91cb88976 Mon Sep 17 00:00:00 2001 From: Felix Lange Date: Tue, 14 Oct 2014 19:07:54 +0200 Subject: ethlog: verify that Flush is blocking in TestLoggerFlush --- ethlog/loggers_test.go | 30 ++++++++++++++++++++++++------ 1 file changed, 24 insertions(+), 6 deletions(-) (limited to 'ethlog/loggers_test.go') diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go index ffc30e21f..0466a3d59 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) { -- cgit v1.2.3 From 50f5ba5b0cfdf02cd87a9070676bd3c21c217296 Mon Sep 17 00:00:00 2001 From: Felix Lange Date: Thu, 16 Oct 2014 10:48:33 +0200 Subject: 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(-) (limited to 'ethlog/loggers_test.go') diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go index 0466a3d59..23f649312 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) { -- cgit v1.2.3 From c090a77f1c9bc890e67a00fb47a1c23c8769799d Mon Sep 17 00:00:00 2001 From: Felix Lange Date: Thu, 16 Oct 2014 10:50:51 +0200 Subject: 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_test.go | 20 ++++---------------- 1 file changed, 4 insertions(+), 16 deletions(-) (limited to 'ethlog/loggers_test.go') diff --git a/ethlog/loggers_test.go b/ethlog/loggers_test.go index 23f649312..cf92e3cc6 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) { -- cgit v1.2.3