diff --git a/logtail/logtail_test.go b/logtail/logtail_test.go index 576cc1888..6ee5627d8 100644 --- a/logtail/logtail_test.go +++ b/logtail/logtail_test.go @@ -6,8 +6,12 @@ import ( "context" + "encoding/json" + "io" + "io/ioutil" "net/http" "net/http/httptest" + "strings" "testing" "time" ) @@ -26,28 +30,177 @@ func(w http.ResponseWriter, r *http.Request) {})) l.Shutdown(ctx) } -func TestUploadMessages(t *testing.T) { +// accumulate some logs before the server becomes available, exercise the drain path +func TestDrainPendingMessages(t *testing.T) { ctx, cancel := context.WithCancel(context.Background()) - uploads := 0 + uploaded := make(chan int) + bodytext := "" testServ := httptest.NewServer(http.HandlerFunc( func(w http.ResponseWriter, r *http.Request) { - w.Header().Set("Content-Type", "application/json; charset=utf-8") - uploads += 1 + body, err := ioutil.ReadAll(r.Body) + if err != nil { + t.Error("failed to read HTTP request") + } + bodytext += "\n" + string(body) + + uploaded <- 0 })) defer testServ.Close() l := NewLogger(Config{BaseURL: testServ.URL}, t.Logf) - for i := 1; i < 10; i++ { + for i := 0; i < 3; i++ { l.Write([]byte("log line")) } + select { + case <-uploaded: + if strings.Count(bodytext, "log line") == 3 { + break + } + case <-time.After(1 * time.Second): + t.Errorf("Timed out waiting for log uploads") + } + l.Shutdown(ctx) cancel() - if uploads == 0 { - t.Error("no log uploads") + if strings.Count(bodytext, "log line") != 3 { + t.Errorf("got %q; want: 3 copies of %q", bodytext, "log line") } } +func TestEncodeAndUploadMessages(t *testing.T) { + ctx, cancel := context.WithCancel(context.Background()) + var jsonbody []byte + uploaded := make(chan int) + testServ := httptest.NewServer(http.HandlerFunc( + func(w http.ResponseWriter, r *http.Request) { + body, err := ioutil.ReadAll(r.Body) + if err != nil { + t.Error("failed to read HTTP request") + } + jsonbody = body + uploaded <- 0 + })) + defer testServ.Close() + + l := NewLogger(Config{BaseURL: testServ.URL}, t.Logf) + + // There is always an initial "logtail started" message + <-uploaded + if !strings.Contains(string(jsonbody), "started") { + t.Errorf("initialize: got:%q; want:%q", string(jsonbody), "started") + } + + tests := []struct { + name string + log string + want string + }{ + { + "plain text", + "log line", + "log line", + }, + { + "simple JSON", + `{"text": "log line"}`, + "log line", + }, + { + "escaped characters", + `\b\f\n\r\t"\\`, + `\b\f\n\r\t"\\`, + }, + } + + for _, tt := range tests { + io.WriteString(l, tt.log) + <-uploaded + + data := make(map[string]interface{}) + err := json.Unmarshal(jsonbody, &data) + if err != nil { + t.Error(err) + } + + got, ok := data["text"] + if ok { + if got != tt.want { + t.Errorf("%s: got %q; want %q", tt.name, got.(string), tt.want) + } + } else { + t.Errorf("no text in: %v", data) + } + + ltail, ok := data["logtail"] + if ok { + logtailmap := ltail.(map[string]interface{}) + _, ok = logtailmap["client_time"] + if !ok { + t.Errorf("%s: no client_time present", tt.name) + } + } else { + t.Errorf("%s: no logtail map present", tt.name) + } + } + + // test some special cases + + // JSON log message already contains a logtail field. + io.WriteString(l, `{"logtail": "LOGTAIL", "text": "text"}`) + <-uploaded + data := make(map[string]interface{}) + err := json.Unmarshal(jsonbody, &data) + if err != nil { + t.Error(err) + } + error_has_logtail, ok := data["error_has_logtail"] + if ok { + if error_has_logtail.(string) != "LOGTAIL" { + t.Errorf("error_has_logtail: got:%q; want:%q", + error_has_logtail.(string), "LOGTAIL") + } + } else { + t.Errorf("no error_has_logtail field: %v", data) + } + + // skipClientTime to omit the logtail metadata + l.skipClientTime = true + io.WriteString(l, "text") + <-uploaded + data = make(map[string]interface{}) + err = json.Unmarshal(jsonbody, &data) + if err != nil { + t.Error(err) + } + _, ok = data["logtail"] + if ok { + t.Errorf("skipClientTime: unexpected logtail map present: %v", data) + } + + // lowMem + long string + l.skipClientTime = false + l.lowMem = true + longStr := strings.Repeat("0", 512) + io.WriteString(l, longStr) + <-uploaded + data = make(map[string]interface{}) + err = json.Unmarshal(jsonbody, &data) + if err != nil { + t.Error(err) + } + text, ok := data["text"] + if !ok { + t.Errorf("lowMem: no text %v", data) + } + if len(text.(string)) > 300 { + t.Errorf("lowMem: got %d chars; want <300 chars", len(text.(string))) + } + + l.Shutdown(ctx) + cancel() +} + var sink []byte func TestLoggerEncodeTextAllocs(t *testing.T) { @@ -75,3 +228,52 @@ func TestLoggerWriteLength(t *testing.T) { t.Errorf("logger.Write wrote %d bytes, expected %d", n, len(inBuf)) } } + +func TestParseAndRemoveLogLevel(t *testing.T) { + tests := []struct { + log string + wantLevel int + wantLog string + }{ + { + "no level", + 0, + "no level", + }, + { + "[v1] level 1", + 1, + "level 1", + }, + { + "level 1 [v1] ", + 1, + "level 1 ", + }, + { + "[v2] level 2", + 2, + "level 2", + }, + { + "level [v2] 2", + 2, + "level 2", + }, + { + "[v3] no level 3", + 0, + "[v3] no level 3", + }, + } + + for _, tt := range tests { + gotLevel, gotLog := parseAndRemoveLogLevel([]byte(tt.log)) + if gotLevel != tt.wantLevel { + t.Errorf("%q: got:%d; want %d", tt.log, gotLevel, tt.wantLevel) + } + if string(gotLog) != tt.wantLog { + t.Errorf("%q: got:%q; want %q", tt.log, gotLog, tt.wantLog) + } + } +}