search

brimdata / super

A novel data lake based on super-structured data
https://zed.brimdata.io/
BSD 3-Clause "New" or "Revised" License
1.38k stars 64 forks source link

Timeout in TestJournalConcurrent #5281

Open philrz opened 4 weeks ago

philrz commented 4 weeks ago

CI recently had a test failure in lake/journal/journal_test.go. Upon checking with @nwt I was informed:

It's a bug in the test, not the implementation, and so it isn’t user-facing.

However, to my non-Dev eyes that wasn't immediately obvious, so I'm capturing it in an issue so that way if it happens again I'll know not to panic, and maybe at some point the test can be improved.

The full stack trace from this recent failure:

panic: test timed out after 10m0s
running tests:
    TestJournalConcurrent (10m0s)

goroutine 61 [running]:
testing.(*M).startAlarm.func1()
    /opt/hostedtoolcache/go/1.21.13/x64/src/testing/testing.go:2259 +0x3b9
created by time.goFunc
    /opt/hostedtoolcache/go/1.21.13/x64/src/time/sleep.go:176 +0x2d

    /opt/hostedtoolcache/go/1.21.13/x64/src/testing/internal/testdeps/deps.go:78 +0x2a
internal/testlog.Open({0xc000181080?, 0x5f92a6?})
    /opt/hostedtoolcache/go/1.21.13/x64/src/internal/testlog/log.go:60 +0x8b
os.OpenFile({0xc000181080, 0x2e}, 0x2c1, 0x8b90a0?)
    /opt/hostedtoolcache/go/1.21.13/x64/src/os/file.go:333 +0x26
github.com/brimdata/zed/pkg/storage.(*FileSystem).PutIfNotExists(0xc000249f50, {0x2?, 0xc000096610?}, 0xc000184480, {0xc000096600, 0xc, 0xc})
    /home/runner/work/zed/zed/pkg/storage/file.go:51 +0x73
github.com/brimdata/zed/pkg/storage.(*Router).PutIfNotExists(0xc000249f80?, {0xae5020, 0xdd4d40}, 0x2?, {0xc000096600, 0xc, 0xc})
    /home/runner/work/zed/zed/pkg/storage/router.go:83 +0x72
github.com/brimdata/zed/lake/journal.(*Queue).CommitAt(0xc000249f80, {0xae5020, 0xdd4d40}, 0xc000052108?, {0xc000096600, 0xc, 0xc})
    /home/runner/work/zed/zed/lake/journal/queue.go:112 +0xa2
github.com/brimdata/zed/lake/journal.(*Queue).Commit(0xc000249f80, {0xae5020, 0xdd4d40}, {0xc000096600, 0xc, 0xc})
    /home/runner/work/zed/zed/lake/journal/queue.go:100 +0x96
github.com/brimdata/zed/lake/journal.TestJournalConcurrent.func1(0x0?)
    /home/runner/work/zed/zed/lake/journal/journal_test.go:29 +0x85
created by github.com/brimdata/zed/lake/journal.TestJournalConcurrent in goroutine 6
    /home/runner/work/zed/zed/lake/journal/journal_test.go:27 +0x65

goroutine 47 [sync.Mutex.Lock]:
sync.runtime_SemacquireMutex(0x897ee0?, 0xf2?, 0x2f[310](https://github.com/brimdata/zed/actions/runs/10865226064/job/30151453342#step:8:311)00000897ea0?)
    /opt/hostedtoolcache/go/1.21.13/x64/src/runtime/sema.go:77 +0x25
sync.(*Mutex).lockSlow(0xda4e20)
    /opt/hostedtoolcache/go/1.21.13/x64/src/sync/mutex.go:171 +0x15d
sync.(*Mutex).Lock(...)
    /opt/hostedtoolcache/go/1.21.13/x64/src/sync/mutex.go:90
testing/internal/testdeps.(*testLog).add(0xda4e20, {0x95fcd7, 0x4}, {0xc0000daae0, 0x2e})
    /opt/hostedtoolcache/go/1.21.13/x64/src/testing/internal/testdeps/deps.go:95 +0x86
testing/internal/testdeps.(*testLog).Open(0xc0000daae0?, {0xc0000daae0?, 0xc000343d40?})
    /opt/hostedtoolcache/go/1.21.13/x64/src/testing/internal/testdeps/deps.go:78 +0x2a
internal/testlog.Open({0xc0000daae0?, 0x5f92a6?})
    /opt/hostedtoolcache/go/1.21.13/x64/src/internal/testlog/log.go:60 +0x8b
os.OpenFile({0xc0000daae0, 0x2e}, 0x2c1, 0x8b90a0?)
    /opt/hostedtoolcache/go/1.21.13/x64/src/os/file.go:333 +0x26
github.com/brimdata/zed/pkg/storage.(*FileSystem).PutIfNotExists(0xc000249f50, {0x2?, 0xc0002c3f80?}, 0xc0000d8f30, {0xc000097030, 0xc, 0xc})
    /home/runner/work/zed/zed/pkg/storage/file.go:51 +0x73
github.com/brimdata/zed/pkg/storage.(*Router).PutIfNotExists(0xc000249f80?, {0xae5020, 0xdd4d40}, 0x2?, {0xc000097030, 0xc, 0xc})
    /home/runner/work/zed/zed/pkg/storage/router.go:83 +0x72
github.com/brimdata/zed/lake/journal.(*Queue).CommitAt(0xc000249f80, {0xae5020, 0xdd4d40}, 0xc000052108?, {0xc000097030, 0xc, 0xc})
    /home/runner/work/zed/zed/lake/journal/queue.go:112 +0xa2
github.com/brimdata/zed/lake/journal.(*Queue).Commit(0xc000249f80, {0xae5020, 0xdd4d40}, {0xc000097030, 0xc, 0xc})
    /home/runner/work/zed/zed/lake/journal/queue.go:100 +0x96
github.com/brimdata/zed/lake/journal.TestJournalConcurrent.func1(0x0?)
    /home/runner/work/zed/zed/lake/journal/journal_test.go:29 +0x85
created by github.com/brimdata/zed/lake/journal.TestJournalConcurrent in goroutine 6
    /home/runner/work/zed/zed/lake/journal/journal_test.go:27 +0x65

goroutine 52 [sync.Mutex.Lock]:
sync.runtime_SemacquireMutex(0x897ee0?, 0xf2?, 0x2f31000000897ea0?)
    /opt/hostedtoolcache/go/1.21.13/x64/src/runtime/sema.go:77 +0x25
sync.(*Mutex).lockSlow(0xda4e20)
    /opt/hostedtoolcache/go/1.21.13/x64/src/sync/mutex.go:171 +0x15d
sync.(*Mutex).Lock(...)
    /opt/hostedtoolcache/go/1.21.13/x64/src/sync/mutex.go:90
testing/internal/testdeps.(*testLog).add(0xda4e20, {0x95fcd7, 0x4}, {0xc0000f0480, 0x2e})
    /opt/hostedtoolcache/go/1.21.13/x64/src/testing/internal/testdeps/deps.go:95 +0x86
testing/internal/testdeps.(*testLog).Open(0xc0000f0480?, {0xc0000f0480?, 0xc000356d40?})
    /opt/hostedtoolcache/go/1.21.13/x64/src/testing/internal/testdeps/deps.go:78 +0x2a
internal/testlog.Open({0xc0000f0480?, 0x5f92a6?})
    /opt/hostedtoolcache/go/1.21.13/x64/src/internal/testlog/log.go:60 +0x8b
os.OpenFile({0xc0000f0480, 0x2e}, 0x2c1, 0x8b90a0?)
    /opt/hostedtoolcache/go/1.21.13/x64/src/os/file.go:[333](https://github.com/brimdata/zed/actions/runs/10865226064/job/30151453342#step:8:334) +0x26
github.com/brimdata/zed/pkg/storage.(*FileSystem).PutIfNotExists(0xc000249f50, {0x2?, 0xc0000e42b0?}, 0xc0000f42d0, {0xc0000e42a0, 0xc, 0xc})
    /home/runner/work/zed/zed/pkg/storage/file.go:51 +0x73
github.com/brimdata/zed/pkg/storage.(*Router).PutIfNotExists(0xc000249f80?, {0xae5020, 0xdd4d40}, 0x2?, {0xc0000e42a0, 0xc, 0xc})
    /home/runner/work/zed/zed/pkg/storage/router.go:83 +0x72
github.com/brimdata/zed/lake/journal.(*Queue).CommitAt(0xc000249f80, {0xae5020, 0xdd4d40}, 0xc000052108?, {0xc0000e42a0, 0xc, 0xc})
    /home/runner/work/zed/zed/lake/journal/queue.go:112 +0xa2
github.com/brimdata/zed/lake/journal.(*Queue).Commit(0xc000249f80, {0xae5020, 0xdd4d40}, {0xc0000e42a0, 0xc, 0xc})
    /home/runner/work/zed/zed/lake/journal/queue.go:100 +0x96
github.com/brimdata/zed/lake/journal.TestJournalConcurrent.func1(0x0?)
    /home/runner/work/zed/zed/lake/journal/journal_test.go:29 +0x85
created by github.com/brimdata/zed/lake/journal.TestJournalConcurrent in goroutine 6
    /home/runner/work/zed/zed/lake/journal/journal_test.go:27 +0x65
FAIL    github.com/brimdata/zed/lake/journal    600.020s