github.com/openshift/installer@v1.4.17/pkg/metrics/timer/timer_test.go (about) 1 package timer 2 3 import ( 4 "bytes" 5 "encoding/json" 6 "fmt" 7 "strings" 8 "testing" 9 "time" 10 11 "github.com/sirupsen/logrus" 12 ) 13 14 func convertToFormat(buf bytes.Buffer) string { 15 output := buf.String() 16 17 outputText := "" 18 19 for _, item := range strings.Split(output, "\n") { 20 var dat map[string]interface{} 21 22 if err := json.Unmarshal([]byte(item), &dat); err != nil { 23 continue 24 } 25 outputText += dat["msg"].(string) + "\n" 26 } 27 28 return outputText 29 } 30 31 func TestBasicLogSummaryMultipleStages(t *testing.T) { 32 timer := NewTimer() 33 34 timer.StartTimer(TotalTimeElapsed) 35 timer.StartTimer("testStage1") 36 timer.StartTimer("testStage2") 37 timer.StartTimer("testStage3") 38 timer.StartTimer("testStage4") 39 40 time.Sleep(5 * time.Second) 41 42 timer.StopTimer("testStage1") 43 timer.StopTimer("testStage2") 44 timer.StopTimer("testStage3") 45 timer.StopTimer("testStage4") 46 timer.StopTimer(TotalTimeElapsed) 47 48 timeElapsed := "Time elapsed per stage:\n" 49 time1 := fmt.Sprintf("testStage1: %s\n", timer.stageTimes["testStage1"]) 50 time2 := fmt.Sprintf("testStage2: %s\n", timer.stageTimes["testStage2"]) 51 time3 := fmt.Sprintf("testStage3: %s\n", timer.stageTimes["testStage3"]) 52 time4 := fmt.Sprintf("testStage4: %s\n", timer.stageTimes["testStage4"]) 53 timeStageElapsed := fmt.Sprintf("Time elapsed: %s\n", timer.stageTimes[TotalTimeElapsed]) 54 55 text := timeElapsed + time1 + time2 + time3 + time4 + timeStageElapsed 56 57 textOutput := bytes.Buffer{} 58 59 logger := logrus.New() 60 logger.Out = &textOutput 61 logger.Level = logrus.DebugLevel 62 logger.Formatter = &logrus.JSONFormatter{} 63 64 timer.LogSummary(logger) 65 66 outputText := convertToFormat(textOutput) 67 68 if text != outputText { 69 t.Fatalf("expected message summary printed to be %s, but got %s", text, outputText) 70 } 71 } 72 73 func TestTotalOnlyLogSummary(t *testing.T) { 74 timer := NewTimer() 75 76 timer.StartTimer(TotalTimeElapsed) 77 time.Sleep(5 * time.Second) 78 timer.StopTimer(TotalTimeElapsed) 79 80 timeStageElapsed := fmt.Sprintf("Time elapsed: %s\n", timer.stageTimes[TotalTimeElapsed]) 81 82 textOutput := bytes.Buffer{} 83 84 logger := logrus.New() 85 logger.Out = &textOutput 86 logger.Level = logrus.DebugLevel 87 logger.Formatter = &logrus.JSONFormatter{} 88 89 timer.LogSummary(logger) 90 91 outputText := convertToFormat(textOutput) 92 93 if timeStageElapsed != outputText { 94 t.Fatalf("expected message summary printed to be %s, but got %s", timeStageElapsed, outputText) 95 } 96 } 97 98 func TestStartAndStopTimer(t *testing.T) { 99 timerTotal := NewTimer() 100 101 timerTotal.StartTimer(TotalTimeElapsed) 102 time.Sleep(5 * time.Second) 103 104 duration := time.Since(timerTotal.startTimes[TotalTimeElapsed]).Round(time.Second) 105 t.Logf("%s", duration) 106 if duration < 5*time.Second { 107 t.Fatalf("Slept for 5 seconds, expected start time to be 5 seconds old, got %s", duration) 108 } else if duration > 10*time.Second { 109 t.Fatalf("Slept for 5 seconds, expected start time to be close to 5 seconds old, got %s", duration) 110 } 111 timerTotal.StopTimer(TotalTimeElapsed) 112 113 if timerTotal.stageTimes[TotalTimeElapsed] < 5*time.Second || timerTotal.stageTimes[TotalTimeElapsed] > 10*time.Second { 114 t.Fatalf("Slept for 5 seconds, expected duration to be close to 5 seconds old, got %s", timerTotal.stageTimes[TotalTimeElapsed]) 115 } 116 } 117 118 func TestNewTimer(t *testing.T) { 119 timer := NewTimer() 120 if len(timer.listOfStages) != 0 { 121 t.Fatalf("Expected empty list of stages property in the new timer created, got %d", len(timer.listOfStages)) 122 } 123 124 if len(timer.startTimes) != 0 { 125 t.Fatalf("Expected empty list of startTimes property in the new timer created, got %d", len(timer.startTimes)) 126 } 127 128 if len(timer.stageTimes) != 0 { 129 t.Fatalf("Expected empty list of startTimes property in the new timer created, got %d", len(timer.stageTimes)) 130 } 131 }