go.undefinedlabs.com/scopeagent@v0.4.2/instrumentation/logging/logger_test.go (about) 1 package logging 2 3 import ( 4 "fmt" 5 stdlog "log" 6 "os" 7 "regexp" 8 "testing" 9 "time" 10 11 "github.com/opentracing/opentracing-go" 12 13 "go.undefinedlabs.com/scopeagent/tags" 14 ) 15 16 func TestLoggingRegex(t *testing.T) { 17 re := regexp.MustCompile(fmt.Sprintf(logRegexTemplate, stdlog.Prefix())) 18 19 var loglines = [][]string{ 20 {"2009/01/23 01:23:23.123123 /a/b/c/d.go:23: message", "2009/01/23", "01:23:23.123123", "/a/b/c/d.go", "23", "message"}, 21 {"2009/01/23 01:23:23 /a/b/c/d.go:23: message", "2009/01/23", "01:23:23", "/a/b/c/d.go", "23", "message"}, 22 {"2009/01/23 /a/b/c/d.go:23: message", "2009/01/23", "", "/a/b/c/d.go", "23", "message"}, 23 {"/a/b/c/d.go:23: message", "", "", "/a/b/c/d.go", "23", "message"}, 24 25 {"2009/01/23 01:23:23.123123 d.go:23: message", "2009/01/23", "01:23:23.123123", "d.go", "23", "message"}, 26 {"2009/01/23 01:23:23 d.go:23: message", "2009/01/23", "01:23:23", "d.go", "23", "message"}, 27 {"2009/01/23 d.go:23: message", "2009/01/23", "", "d.go", "23", "message"}, 28 {"d.go:23: message", "", "", "d.go", "23", "message"}, 29 30 {"2009/01/23 01:23:23.123123 message", "2009/01/23", "01:23:23.123123", "", "", "message"}, 31 {"2009/01/23 01:23:23 message", "2009/01/23", "01:23:23", "", "", "message"}, 32 {"2009/01/23 message", "2009/01/23", "", "", "", "message"}, 33 {"message", "", "", "", "", "message"}, 34 35 {"2009/01/23 01:23:23.123123 c:/a/b/c/d.go:23: message", "2009/01/23", "01:23:23.123123", "c:/a/b/c/d.go", "23", "message"}, 36 {"2009/01/23 01:23:23 c:/a/b/c/d.go:23: message", "2009/01/23", "01:23:23", "c:/a/b/c/d.go", "23", "message"}, 37 {"2009/01/23 c:/a/b/c/d.go:23: message", "2009/01/23", "", "c:/a/b/c/d.go", "23", "message"}, 38 {"c:/a/b/c/d.go:23: message", "", "", "c:/a/b/c/d.go", "23", "message"}, 39 40 {"2009/01/23 01:23:23.123123 c:\\a\\b\\c\\d.go:23: message", "2009/01/23", "01:23:23.123123", "c:\\a\\b\\c\\d.go", "23", "message"}, 41 {"2009/01/23 01:23:23 c:\\a\\b\\c\\d.go:23: message", "2009/01/23", "01:23:23", "c:\\a\\b\\c\\d.go", "23", "message"}, 42 {"2009/01/23 c:\\a\\b\\c\\d.go:23: message", "2009/01/23", "", "c:\\a\\b\\c\\d.go", "23", "message"}, 43 {"c:\\a\\b\\c\\d.go:23: message", "", "", "c:\\a\\b\\c\\d.go", "23", "message"}, 44 45 {"2009/01/23 01:23:23.123123 Lorem Ipsum is simply dummy text of the printing and typesetting industry. Lorem Ipsum has been the industry's standard dummy text ever since the 1500s, when an unknown printer took a galley of type and scrambled it to make a type specimen book. It has survived not only five centuries, but also the leap into electronic typesetting, remaining essentially unchanged. It was popularised in the 1960s with the release of Letraset sheets containing Lorem Ipsum passages, and more recently with desktop publishing software like Aldus PageMaker including versions of Lorem Ipsum.", 46 "2009/01/23", "01:23:23.123123", "", "", 47 "Lorem Ipsum is simply dummy text of the printing and typesetting industry. Lorem Ipsum has been the industry's standard dummy text ever since the 1500s, when an unknown printer took a galley of type and scrambled it to make a type specimen book. It has survived not only five centuries, but also the leap into electronic typesetting, remaining essentially unchanged. It was popularised in the 1960s with the release of Letraset sheets containing Lorem Ipsum passages, and more recently with desktop publishing software like Aldus PageMaker including versions of Lorem Ipsum."}, 48 49 {"2009/01/23 01:23:23.123123 Lorem Ipsum is simply dummy text of the printing and typesetting industry. Lorem Ipsum has been the industry's standard dummy text ever since the 1500s, when an unknown printer took a galley of type and scrambled it to make a type specimen book. It has survived not only five centuries, but also the leap into electronic typesetting, remaining essentially unchanged. It was popularised in the 1960s with the release of Letraset sheets containing Lorem Ipsum passages, and more recently with desktop publishing software like Aldus PageMaker including versions of Lorem Ipsum.", 50 "2009/01/23", "01:23:23.123123", "", "", 51 "Lorem Ipsum is simply dummy text of the printing and typesetting industry. Lorem Ipsum has been the industry's standard dummy text ever since the 1500s, when an unknown printer took a galley of type and scrambled it to make a type specimen book. It has survived not only five centuries, but also the leap into electronic typesetting, remaining essentially unchanged. It was popularised in the 1960s with the release of Letraset sheets containing Lorem Ipsum passages, and more recently with desktop publishing software like Aldus PageMaker including versions of Lorem Ipsum."}, 52 } 53 54 for i := 0; i < len(loglines); i++ { 55 logline := loglines[i] 56 t.Run(fmt.Sprintf("Value %v", i), func(st *testing.T) { 57 matches := re.FindStringSubmatch(logline[0]) 58 59 for idx := 0; idx <= 5; idx++ { 60 if matches[idx] != logline[idx] { 61 t.Fatalf("Error in line[%v]: %v. Value expected: %v, Actual value: %v", i, logline[0], logline[idx], matches[idx]) 62 } 63 } 64 }) 65 } 66 } 67 68 func TestStandardLoggerInstrumentation(t *testing.T) { 69 stdlog.SetFlags(stdlog.LstdFlags | stdlog.Lmicroseconds | stdlog.Llongfile) 70 PatchStandardLogger() 71 defer UnpatchStandardLogger() 72 73 messages := []string{"Print log", "Println log"} 74 75 stdlog.Print(messages[0]) 76 stdlog.Println(messages[1]) 77 78 checkRecords(t, messages) 79 } 80 81 func TestCustomLoggerInstrumentation(t *testing.T) { 82 logger := stdlog.New(os.Stdout, "", stdlog.LstdFlags|stdlog.Lmicroseconds|stdlog.Llongfile) 83 PatchLogger(logger) 84 defer UnpatchLogger(logger) 85 86 messages := []string{"Print log", "Println log"} 87 88 logger.Print(messages[0]) 89 logger.Println(messages[1]) 90 91 checkRecords(t, messages) 92 } 93 94 func TestStdOutInstrumentation(t *testing.T) { 95 PatchStdOut() 96 defer UnpatchStdOut() 97 Reset() 98 99 messages := []string{"Println log", "Println log"} 100 101 fmt.Println(messages[0]) 102 fmt.Println(messages[1]) 103 104 <-time.After(time.Second) 105 106 checkRecords(t, messages) 107 } 108 109 func checkRecords(t *testing.T, messages []string) { 110 records := GetRecords() 111 112 if len(records) != 2 { 113 t.Fatalf("error in the number of records, expected: 2, actual: %d", len(records)) 114 } 115 116 for _, msg := range messages { 117 if !checkMessage(msg, records) { 118 t.Fatalf("the message '%s' was not in the log records", msg) 119 } 120 } 121 } 122 123 func checkMessage(msg string, records []opentracing.LogRecord) bool { 124 for _, rec := range records { 125 for _, field := range rec.Fields { 126 if field.Key() == tags.EventMessage { 127 if msg == fmt.Sprint(field.Value()) { 128 return true 129 } 130 } 131 } 132 } 133 return false 134 } 135 136 func BenchmarkPatchStandardLogger(b *testing.B) { 137 for i := 0; i < b.N; i++ { 138 PatchStandardLogger() 139 UnpatchStandardLogger() 140 } 141 } 142 143 var lg *stdlog.Logger 144 145 func BenchmarkPatchLogger(b *testing.B) { 146 for i := 0; i < b.N; i++ { 147 lg = stdlog.New(os.Stdout, "", stdlog.Llongfile|stdlog.Lmicroseconds) 148 PatchLogger(lg) 149 UnpatchLogger(lg) 150 } 151 }