github.com/ActiveState/cli@v0.0.0-20240508170324-6801f60cd051/test/integration/performance_int_test.go (about) 1 package integration 2 3 import ( 4 "bytes" 5 "fmt" 6 "io" 7 "log" 8 "regexp" 9 "sort" 10 "strconv" 11 "strings" 12 "testing" 13 "time" 14 15 "github.com/ActiveState/cli/internal/constants" 16 "github.com/ActiveState/cli/internal/errs" 17 "github.com/ActiveState/cli/internal/osutils" 18 "github.com/ActiveState/cli/internal/testhelpers/suite" 19 "github.com/ActiveState/termtest" 20 21 "github.com/ActiveState/cli/internal/testhelpers/e2e" 22 "github.com/ActiveState/cli/internal/testhelpers/tagsuite" 23 ) 24 25 // The max time is based on the median execution times across platforms at the time that this was configured 26 // Increasing this should be a LAST RESORT 27 var StateVersionMaxTime = 100 * time.Millisecond // DO NOT CHANGE WITHOUT DISCUSSION WITH THE TEAM 28 var StateVersionTotalSamples = 10 29 30 type PerformanceIntegrationTestSuite struct { 31 tagsuite.Suite 32 } 33 34 func (suite *PerformanceIntegrationTestSuite) TestVersionPerformance() { 35 suite.OnlyRunForTags(tagsuite.Performance) 36 ts := e2e.New(suite.T(), false) 37 defer ts.Close() 38 39 // Start svc first, as we don't want to measure svc startup time which would only happen the very first invocation 40 stdout, stderr, err := osutils.ExecSimple(ts.SvcExe, []string{"start"}, []string{}) 41 suite.Require().NoError(err, fmt.Sprintf("Full error:\n%v\nstdout:\n%s\nstderr:\n%s", errs.JoinMessage(err), stdout, stderr)) 42 43 performanceTest([]string{"--version"}, "", StateVersionTotalSamples, StateVersionMaxTime, false, &suite.Suite, ts) 44 } 45 46 func TestPerformanceIntegrationTestSuite(t *testing.T) { 47 suite.Run(t, new(PerformanceIntegrationTestSuite)) 48 } 49 50 func performanceTest(commands []string, expect string, samples int, maxTime time.Duration, verbose bool, suite *tagsuite.Suite, ts *e2e.Session) time.Duration { 51 rx := regexp.MustCompile(`Profiling: main took .*\((\d+)\)`) 52 var firstEntry, firstLogs string 53 times := []time.Duration{} 54 var total time.Duration 55 for x := 0; x < samples+1; x++ { 56 opts := []e2e.SpawnOptSetter{ 57 e2e.OptArgs(commands...), 58 e2e.OptAppendEnv(constants.DisableUpdates+"=true", constants.ProfileEnvVarName+"=true"), 59 } 60 termtestLogs := &bytes.Buffer{} 61 if verbose { 62 opts = append(opts, e2e.OptTermTest(func(o *termtest.Opts) error { 63 o.Logger = log.New(termtestLogs, "TermTest: ", log.LstdFlags|log.Lshortfile) 64 return nil 65 })) 66 } 67 cp := ts.SpawnWithOpts(opts...) 68 if expect != "" { 69 cp.Expect(expect) 70 } 71 cp.ExpectExitCode(0) 72 logs, err := io.ReadAll(termtestLogs) 73 suite.NoError(err) 74 v := rx.FindStringSubmatch(cp.Output()) 75 if len(v) < 2 { 76 suite.T().Fatalf("Could not find '%s' in output:\n%s\n\ntermtest logs:\n%s", rx.String(), cp.Output(), logs) 77 } 78 durMS, err := strconv.Atoi(v[1]) 79 suite.Require().NoError(err) 80 dur := time.Millisecond * time.Duration(durMS) 81 82 if firstEntry == "" { 83 firstEntry = cp.Output() 84 firstLogs = ts.DebugLogsDump() 85 } 86 if x == 0 { 87 // Skip the first one as this one will always be slower due to having to wait for state-svc or sourcing a runtime 88 // Also pause for a second allow the second run to use the cached results from the first 89 time.Sleep(1 * time.Second) 90 continue 91 } 92 times = append(times, dur) 93 total = total + dur 94 } 95 96 sort.Slice(times, func(i, j int) bool { return times[i] < times[j] }) 97 mid := len(times) / 2 98 var median time.Duration 99 if len(times)%2 == 0 { 100 median = (times[mid-1] + times[mid]) / 2 101 } else { 102 median = times[mid] 103 } 104 105 if median.Milliseconds() > maxTime.Milliseconds() { 106 suite.FailNow( 107 fmt.Sprintf(`'%s' is performing poorly! 108 Median duration: %s 109 Maximum: %s 110 Total: %s 111 Totals: %v 112 113 Output of first run: 114 %s 115 116 %s`, 117 strings.Join(commands, " "), 118 median.String(), 119 maxTime.String(), 120 time.Duration(total).String(), 121 times, 122 firstEntry, 123 firstLogs)) 124 } 125 126 return median 127 }