main.go 9.7 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410
  1. package main
  2. import (
  3. "bufio"
  4. "encoding/json"
  5. "fmt"
  6. "io"
  7. "os"
  8. "os/exec"
  9. "path/filepath"
  10. "strings"
  11. "time"
  12. log "github.com/sirupsen/logrus"
  13. )
  14. const (
  15. defaultLogFile = "flakey-test-runs.log"
  16. defaultJSONLFile = "flakey-test-runs.jsonl"
  17. )
  18. type testEvent struct {
  19. Time time.Time `json:"Time"`
  20. Action string `json:"Action"`
  21. Package string `json:"Package"`
  22. Test string `json:"Test"`
  23. Output string `json:"Output"`
  24. Elapsed float64 `json:"Elapsed"`
  25. }
  26. type testFailure struct {
  27. Package string `json:"package"`
  28. Test string `json:"test"`
  29. Output string `json:"output"`
  30. }
  31. type runSummary struct {
  32. Passes int `json:"passes"`
  33. Failures int `json:"failures"`
  34. Skipped int `json:"skipped"`
  35. }
  36. type jsonlRecord struct {
  37. Run int `json:"run"`
  38. Timestamp string `json:"timestamp"`
  39. ExitCode int `json:"exitCode"`
  40. DurationMs int64 `json:"durationMs"`
  41. Passes int `json:"passes"`
  42. Failures int `json:"failures"`
  43. Skipped int `json:"skipped"`
  44. FailureDetails []testFailure `json:"failureDetails"`
  45. }
  46. type testRunState struct {
  47. summary runSummary
  48. failures []testFailure
  49. failureOutput map[string]*strings.Builder
  50. }
  51. func initLog() {
  52. logFormat := os.Getenv("OLIVETIN_LOG_FORMAT")
  53. if logFormat == "json" {
  54. log.SetFormatter(&log.JSONFormatter{})
  55. } else {
  56. log.SetFormatter(&log.TextFormatter{
  57. FullTimestamp: true,
  58. ForceQuote: true,
  59. })
  60. }
  61. log.SetLevel(log.InfoLevel)
  62. }
  63. func hasGoMod(dir string) bool {
  64. stat, err := os.Stat(filepath.Join(dir, "go.mod"))
  65. return err == nil && !stat.IsDir()
  66. }
  67. func rootFromExecutable() (string, bool) {
  68. exe, err := os.Executable()
  69. if err != nil {
  70. return "", false
  71. }
  72. candidate := filepath.Join(filepath.Dir(exe), "..", "..")
  73. if hasGoMod(candidate) {
  74. return candidate, true
  75. }
  76. return "", false
  77. }
  78. func rootFromWorkingDir() string {
  79. wd, err := os.Getwd()
  80. if err != nil {
  81. return "."
  82. }
  83. if hasGoMod(wd) {
  84. return wd
  85. }
  86. return filepath.Join(wd, "..")
  87. }
  88. func serviceRoot() string {
  89. if root, ok := rootFromExecutable(); ok {
  90. return root
  91. }
  92. return rootFromWorkingDir()
  93. }
  94. func envOrDefault(name, fallback string) string {
  95. if value := strings.TrimSpace(os.Getenv(name)); value != "" {
  96. return value
  97. }
  98. return fallback
  99. }
  100. func formatFailure(failure testFailure) string {
  101. lines := []string{
  102. fmt.Sprintf("FAILURE: %s", failure.Test),
  103. fmt.Sprintf(" package: %s", failure.Package),
  104. }
  105. output := strings.TrimSpace(failure.Output)
  106. if output == "" {
  107. output = "unknown"
  108. }
  109. lines = append(lines, fmt.Sprintf(" output: %s", output))
  110. return strings.Join(lines, "\n")
  111. }
  112. func formatRunCounts(summary runSummary) string {
  113. return fmt.Sprintf("%d pass %d fail %d skip", summary.Passes, summary.Failures, summary.Skipped)
  114. }
  115. func runResultLabel(exitCode int) string {
  116. if exitCode == 0 {
  117. return "PASS"
  118. }
  119. return "FAIL"
  120. }
  121. func buildRunLogBlock(run int, timestamp string, exitCode int, summary runSummary, failures []testFailure, durationMs int64) string {
  122. block := []string{
  123. fmt.Sprintf(
  124. "=== RUN %d | %s | %s | %d pass %d fail %d skip | %.1fs ===",
  125. run,
  126. timestamp,
  127. runResultLabel(exitCode),
  128. summary.Passes,
  129. summary.Failures,
  130. summary.Skipped,
  131. float64(durationMs)/1000,
  132. ),
  133. }
  134. for _, failure := range failures {
  135. block = append(block, formatFailure(failure))
  136. }
  137. block = append(block, "")
  138. return strings.Join(block, "\n") + "\n"
  139. }
  140. func appendJSONLRecord(jsonlFile string, run int, timestamp string, exitCode int, durationMs int64, summary runSummary, failures []testFailure) error {
  141. record := jsonlRecord{
  142. Run: run,
  143. Timestamp: timestamp,
  144. ExitCode: exitCode,
  145. DurationMs: durationMs,
  146. Passes: summary.Passes,
  147. Failures: summary.Failures,
  148. Skipped: summary.Skipped,
  149. FailureDetails: failures,
  150. }
  151. encoded, err := json.Marshal(record)
  152. if err != nil {
  153. return err
  154. }
  155. return appendFile(jsonlFile, string(encoded)+"\n")
  156. }
  157. func appendRunLog(logFile, jsonlFile string, run, exitCode int, summary runSummary, failures []testFailure, durationMs int64) error {
  158. timestamp := time.Now().UTC().Format(time.RFC3339)
  159. if err := appendFile(logFile, buildRunLogBlock(run, timestamp, exitCode, summary, failures, durationMs)); err != nil {
  160. return err
  161. }
  162. return appendJSONLRecord(jsonlFile, run, timestamp, exitCode, durationMs, summary, failures)
  163. }
  164. func appendFile(path, content string) error {
  165. file, err := os.OpenFile(path, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o644)
  166. if err != nil {
  167. return err
  168. }
  169. defer file.Close()
  170. _, err = file.WriteString(content)
  171. return err
  172. }
  173. func newTestRunState() *testRunState {
  174. return &testRunState{
  175. failures: make([]testFailure, 0),
  176. failureOutput: make(map[string]*strings.Builder),
  177. }
  178. }
  179. func failureKey(pkg, test string) string {
  180. return pkg + "\x00" + test
  181. }
  182. func (state *testRunState) handlePass(event testEvent) {
  183. if event.Test == "" {
  184. return
  185. }
  186. state.summary.Passes++
  187. }
  188. func (state *testRunState) handleSkip(event testEvent) {
  189. if event.Test == "" {
  190. return
  191. }
  192. state.summary.Skipped++
  193. }
  194. func (state *testRunState) handleFail(event testEvent) {
  195. if event.Test == "" {
  196. return
  197. }
  198. state.summary.Failures++
  199. key := failureKey(event.Package, event.Test)
  200. output := ""
  201. if builder, ok := state.failureOutput[key]; ok {
  202. output = strings.TrimSpace(builder.String())
  203. } else {
  204. state.failureOutput[key] = &strings.Builder{}
  205. }
  206. state.failures = append(state.failures, testFailure{
  207. Package: event.Package,
  208. Test: event.Test,
  209. Output: output,
  210. })
  211. }
  212. func (state *testRunState) handleOutput(event testEvent) {
  213. if event.Test == "" {
  214. return
  215. }
  216. key := failureKey(event.Package, event.Test)
  217. builder, ok := state.failureOutput[key]
  218. if !ok {
  219. builder = &strings.Builder{}
  220. state.failureOutput[key] = builder
  221. }
  222. builder.WriteString(event.Output)
  223. }
  224. type testEventHandler func(*testRunState, testEvent)
  225. var testEventHandlers = map[string]testEventHandler{
  226. "pass": (*testRunState).handlePass,
  227. "fail": (*testRunState).handleFail,
  228. "skip": (*testRunState).handleSkip,
  229. "output": (*testRunState).handleOutput,
  230. }
  231. func (state *testRunState) processEvent(event testEvent) {
  232. handler, ok := testEventHandlers[event.Action]
  233. if !ok {
  234. return
  235. }
  236. handler(state, event)
  237. }
  238. func (state *testRunState) finalizeFailureOutputs() {
  239. for index := range state.failures {
  240. key := failureKey(state.failures[index].Package, state.failures[index].Test)
  241. if builder, ok := state.failureOutput[key]; ok {
  242. state.failures[index].Output = strings.TrimSpace(builder.String())
  243. }
  244. }
  245. }
  246. func scanTestEvents(stdout io.Reader, state *testRunState) error {
  247. scanner := bufio.NewScanner(stdout)
  248. scanner.Buffer(make([]byte, 0, 64*1024), 1024*1024)
  249. for scanner.Scan() {
  250. var event testEvent
  251. if err := json.Unmarshal(scanner.Bytes(), &event); err != nil {
  252. continue
  253. }
  254. state.processEvent(event)
  255. }
  256. return scanner.Err()
  257. }
  258. func finishTestCommand(cmd *exec.Cmd, state *testRunState) (int, runSummary, []testFailure, error) {
  259. if err := cmd.Wait(); err != nil {
  260. if exitErr, ok := err.(*exec.ExitError); ok {
  261. state.finalizeFailureOutputs()
  262. return exitErr.ExitCode(), state.summary, state.failures, nil
  263. }
  264. return 1, state.summary, state.failures, err
  265. }
  266. return 0, state.summary, state.failures, nil
  267. }
  268. func runTestsOnce(rootDir string) (int, runSummary, []testFailure, error) {
  269. cmd := exec.Command("go", "test", "./...", "-count=1", "-json")
  270. cmd.Dir = rootDir
  271. stdout, err := cmd.StdoutPipe()
  272. if err != nil {
  273. return 1, runSummary{}, nil, err
  274. }
  275. if err := cmd.Start(); err != nil {
  276. return 1, runSummary{}, nil, err
  277. }
  278. state := newTestRunState()
  279. if err := scanTestEvents(stdout, state); err != nil {
  280. return 1, state.summary, state.failures, err
  281. }
  282. return finishTestCommand(cmd, state)
  283. }
  284. func buildLogHeader(logFile, jsonlFile string) string {
  285. return strings.Join([]string{
  286. fmt.Sprintf("# Flaky test run log started %s", time.Now().UTC().Format(time.RFC3339)),
  287. fmt.Sprintf("# Log file: %s", logFile),
  288. fmt.Sprintf("# JSONL file: %s", jsonlFile),
  289. "",
  290. }, "\n") + "\n"
  291. }
  292. func initRunFiles(logFile, jsonlFile string) error {
  293. if err := os.WriteFile(logFile, []byte(buildLogHeader(logFile, jsonlFile)), 0o644); err != nil {
  294. return err
  295. }
  296. return os.WriteFile(jsonlFile, nil, 0o644)
  297. }
  298. func logRunResult(run, exitCode int, summary runSummary, durationMs int64) {
  299. log.Infof(
  300. "Run %d: %s | %s (%.1fs) — logged",
  301. run,
  302. runResultLabel(exitCode),
  303. formatRunCounts(summary),
  304. float64(durationMs)/1000,
  305. )
  306. }
  307. func executeRun(run int, rootDir, logFile, jsonlFile string) (exitCode int, stop bool) {
  308. start := time.Now()
  309. exitCode, summary, failures, err := runTestsOnce(rootDir)
  310. durationMs := time.Since(start).Milliseconds()
  311. if err != nil {
  312. log.WithError(err).Errorf("Run %d failed to execute: %s", run, formatRunCounts(summary))
  313. _ = appendRunLog(logFile, jsonlFile, run, 1, summary, failures, durationMs)
  314. os.Exit(1)
  315. }
  316. if logErr := appendRunLog(logFile, jsonlFile, run, exitCode, summary, failures, durationMs); logErr != nil {
  317. log.WithError(logErr).Fatal("failed to append run log")
  318. }
  319. logRunResult(run, exitCode, summary, durationMs)
  320. return exitCode, exitCode != 0
  321. }
  322. func main() {
  323. initLog()
  324. rootDir := serviceRoot()
  325. logFile := envOrDefault("FLAKEY_LOG_FILE", filepath.Join(rootDir, defaultLogFile))
  326. jsonlFile := envOrDefault("FLAKEY_JSONL_FILE", filepath.Join(rootDir, defaultJSONLFile))
  327. if err := initRunFiles(logFile, jsonlFile); err != nil {
  328. log.WithError(err).Fatal("failed to initialize output files")
  329. }
  330. log.Infof("Logging flaky test runs to %s", logFile)
  331. log.Infof("Structured run data: %s", jsonlFile)
  332. run := 0
  333. for {
  334. run++
  335. exitCode, stop := executeRun(run, rootDir, logFile, jsonlFile)
  336. if stop {
  337. log.Errorf("Failure on run %d, stopping. See %s", run, logFile)
  338. os.Exit(exitCode)
  339. }
  340. }
  341. }