log_writer_race_test.go 2.9 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113
  1. package xray
  2. import (
  3. "os"
  4. "path/filepath"
  5. "slices"
  6. "strings"
  7. "sync"
  8. "testing"
  9. )
  10. // TestLogWriterLastLineConcurrent exercises the LogWriter from multiple
  11. // goroutines: Xray drives Write while another goroutine (Process.GetResult)
  12. // reads the last line. Run under `go test -race` this fails on an unguarded
  13. // lastLine field and passes once the access is serialized.
  14. func TestLogWriterLastLineConcurrent(t *testing.T) {
  15. lw := NewLogWriter()
  16. const writers, readers, iterations = 4, 4, 500
  17. var wg sync.WaitGroup
  18. wg.Add(writers + readers)
  19. for range writers {
  20. go func() {
  21. defer wg.Done()
  22. for range iterations {
  23. _, _ = lw.Write([]byte("2024/01/01 00:00:00.000000 [Info] connection accepted\n"))
  24. }
  25. }()
  26. }
  27. for range readers {
  28. go func() {
  29. defer wg.Done()
  30. for range iterations {
  31. _ = lw.LastLine()
  32. }
  33. }()
  34. }
  35. wg.Wait()
  36. }
  37. func crashReportsIn(t *testing.T, dir string) []string {
  38. t.Helper()
  39. entries, err := os.ReadDir(dir)
  40. if err != nil {
  41. t.Fatal(err)
  42. }
  43. var contents []string
  44. for _, e := range entries {
  45. if strings.HasPrefix(e.Name(), crashReportPrefix) {
  46. b, err := os.ReadFile(filepath.Join(dir, e.Name()))
  47. if err != nil {
  48. t.Fatal(err)
  49. }
  50. contents = append(contents, string(b))
  51. }
  52. }
  53. return contents
  54. }
  55. // The Go runtime prints "panic: " with its own write(2), so the pipe hands it
  56. // over as a chunk of its own; the report must still hold the whole traceback.
  57. func TestLogWriterCrashReportHoldsWholePanic(t *testing.T) {
  58. dir := t.TempDir()
  59. t.Setenv("XUI_LOG_FOLDER", dir)
  60. chunks := []string{
  61. "panic: ",
  62. "runtime error: index out of range [3] with length 1\n",
  63. "\ngoroutine 1 [running]:\nmain.main()\n\t/src/main.go:5 +0x1d\n",
  64. "exit status 2",
  65. }
  66. lw := NewLogWriter()
  67. for _, c := range chunks {
  68. _, _ = lw.Write([]byte(c))
  69. }
  70. lw.Flush()
  71. got := crashReportsIn(t, dir)
  72. want := strings.Join(chunks, "")
  73. if len(got) != 1 || got[0] != want {
  74. t.Fatalf("crash reports = %q, want exactly [%q]", got, want)
  75. }
  76. if line := lw.LastLine(); line != "panic: runtime error: index out of range [3] with length 1" {
  77. t.Fatalf("LastLine = %q", line)
  78. }
  79. }
  80. func TestLogWriterOrdinaryLineMentioningPanicIsNotACrash(t *testing.T) {
  81. dir := t.TempDir()
  82. t.Setenv("XUI_LOG_FOLDER", dir)
  83. lw := NewLogWriter()
  84. _, _ = lw.Write([]byte("2026/07/12 15:16:00.000000 [Info] [42] proxy/vless: sniffed domain panic.example.com\n"))
  85. lw.Flush()
  86. if got := crashReportsIn(t, dir); len(got) != 0 {
  87. t.Fatalf("ordinary log line produced crash reports %q", got)
  88. }
  89. }
  90. func TestWriteCrashReportKeepsReportsFromTheSameSecond(t *testing.T) {
  91. dir := t.TempDir()
  92. t.Setenv("XUI_LOG_FOLDER", dir)
  93. for _, m := range []string{"panic: first", "panic: second"} {
  94. if err := writeCrashReport([]byte(m)); err != nil {
  95. t.Fatal(err)
  96. }
  97. }
  98. got := crashReportsIn(t, dir)
  99. slices.Sort(got)
  100. if !slices.Equal(got, []string{"panic: first", "panic: second"}) {
  101. t.Fatalf("crash reports = %q, want both", got)
  102. }
  103. }