Skip to content

Tag nested prefetch io-threads tests valgrind:skip - #64

Open
madolson wants to merge 1 commit into
upstream-unstable-d6415e766from
ai/issue-48
Open

madolson wants to merge 1 commit into
upstream-unstable-d6415e766from
ai/issue-48

Conversation

@madolson

Copy link
Copy Markdown
Owner

The three start_server blocks that #3940 added for nested prefetch run with io-threads 4 io-threads-always-active yes, and in that mode idle IO threads busy-spin on an already-unlocked mutex at src/io_threads.c:423-425 while waitForClientIO spins on the main thread at src/io_threads.c:122-137, both with no syscall and no yield. Valgrind serializes every thread onto one core, so the spinners starve the main thread and the test body barely progresses: the same 200 ZADDs plus 50 pipelined ZSCOREs cost 206 ms in a server without io-threads and 20531 ms with io-threads under valgrind, a 100x gap that blows the 2400s per-test timeout in Daily CI and aborts the rest of the tests/unit/type shard. This tags all three blocks valgrind:skip, which tests/unit/io-threads.tcl:61 and :142 already do for the same reason.

All three need it in one change, because the timeout aborts the run before hash and set are reached, so skipping only zset moves the stall rather than removing it. The busy-spin itself is intentional for io-threads-always-active and is only pathological under valgrind's serialized scheduler, so there is nothing to fix in src/.

Fixes #48

Details

Reproduction

Local, valgrind 3.19.0, 32-core box, built with make valgrind.

The forcing knob is --timeout. The stall is not a hang, so the default 2400s eventually completes locally (109632 ms for the zset test on this box); squeezing the per-test budget to 60s turns it into the exact CI failure. 60s is still ~290x the 206 ms the identical body costs without io-threads.

Before the change, 15/15 failures (3 tests, --loops 5):

$ ./runtest --single unit/type/zset --single unit/type/hash --single unit/type/set \
    --valgrind --only "/nested prefetch" --timeout 60 --loops 5
[TIMEOUT]: clients state report follows.
Test Summary: 0 passed, 15 failed
*** [TIMEOUT]: Zset nested prefetch - ZSCORE correctness with pipelined commands in tests/unit/type/zset.tcl
*** [TIMEOUT]: Hash nested prefetch - HGET correctness with pipelined commands in tests/unit/type/hash.tcl
*** [TIMEOUT]: Set nested prefetch - SISMEMBER correctness with pipelined commands in tests/unit/type/set.tcl
... (same three, five times)

After, the blocks are skipped at tests/support/server.tcl:299 and the run finishes in 5s instead of timing out:

$ ./runtest --single unit/type/zset --single unit/type/hash --single unit/type/set \
    --valgrind --only "/nested prefetch" --timeout 60 --loops 5
Test Summary: 0 passed, 0 failed
\o/ All tests passed without errors!

Native coverage is unchanged, 8 tests x 5 loops:

$ ./runtest --single unit/type/zset --single unit/type/hash --single unit/type/set \
    --only "/nested prefetch" --loops 5
      5 [ok]: Hash nested prefetch - correctness with a forced multi-key batch
      5 [ok]: Hash nested prefetch - HDEL correctness with pipelined commands
      5 [ok]: Hash nested prefetch - HGET correctness with pipelined commands
      5 [ok]: Hash nested prefetch - HMGET multi-field correctness
      5 [ok]: Hash nested prefetch - large non-embedded values exercise value phase
      5 [ok]: Set nested prefetch - SISMEMBER correctness with pipelined commands
      5 [ok]: Zset nested prefetch - short members are looked up safely
      5 [ok]: Zset nested prefetch - ZSCORE correctness with pipelined commands
Test Summary: 40 passed, 0 failed

Isolating the cause to the config, not the body

A scratch suite ran the identical body (del, 200 ZADD, 50 pipelined ZSCORE) in two servers, one plain and one with the exact overrides from tests/unit/type/zset.tcl:3290, both under valgrind pinned to one core with taskset -c 5:

[ok]: REPRO control - no io-threads (206 ms)
[ok]: REPRO io-threads 4 always-active (20531 ms)

Same body, same valgrind, same core. The only variable is io-threads 4 io-threads-always-active yes.

Mechanism

src/io_threads.c:422-425, reached whenever the thread has no work and no pending responses:

            } else {
                /* If it is locked. We should block until main thread unlocks it. */
                pthread_mutex_lock(&io_threads_mutex[id]);
                pthread_mutex_unlock(&io_threads_mutex[id]);
            }

IOThreadsAfterSleep unlocks all of them on any event in the always-active branch at src/io_threads.c:175-183, so both calls return immediately and the while (1) at src/io_threads.c:364 spins. waitForClientIO at src/io_threads.c:122-137 spins on the main thread with only atomic_thread_fence between iterations.

Notes

  • Not a valgrind report. No ==pid== block, no ERROR SUMMARY, in the CI logs or locally. src/valgrind.sup is irrelevant.
  • Branched from upstream/unstable d6415e766 rather than agents/unstable, because agents/unstable is 66 commits behind and does not yet contain #3940, so the lines this patch touches do not exist there.
  • No upstream test-failure issue exists for these test names; searched all 159 by name fragment.

This was generated by AI but verified, with love, by a human.

The three start_server blocks added by #3940 run with io-threads 4 and
io-threads-always-active yes. In that mode idle IO threads busy-spin on
an already-unlocked mutex (src/io_threads.c:423-425) with no syscall and
no yield, and waitForClientIO spins the same way on the main thread
(src/io_threads.c:122-137). Under valgrind every thread is serialized
onto one core, so the spinners starve the main thread and the test body
makes almost no progress.

Measured locally with valgrind 3.19.0: the same 200 ZADDs plus 50
pipelined ZSCOREs takes 206 ms in a server without io-threads and
20531 ms with io-threads 4 io-threads-always-active yes, a 100x gap.
In Daily CI that is enough to blow the 2400s per-test timeout and abort
the rest of the tests/unit/type shard.

tests/unit/io-threads.tcl:61 and :142 already carry valgrind:skip for
the same reason. All three blocks need it in one change, because the
timeout aborts the run before hash and set are reached, so skipping only
zset just moves the stall.

Signed-off-by: Madelyn Olson <matolson@amazon.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

bug Something isn't working

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant