Threading issue not reproducible with rr

[jandem]

Yesterday I was debugging a race condition in the JS shell but I couldn't get it to repro under rr (with or without chaos mode) after thousands of runs. Without rr it reproduced pretty easily.

The bug was that we would wait forever on some pthread condition variable that never got notified in a particular edge case. Maybe more wake ups happen with rr?

I figured out what the problem was, but this is the kind of thing where rr shines so it would be great to understand this better.

[jandem]

I can provide steps to reproduce if anyone is interested.

[rocallahan]

I'm very interested! Tell me more.

[jandem]

I just got it to repro once with rr \o/ So feel free to close this bug as invalid, but it's still harder to repro with rr than without.

STR:

1. Download this (buggy) Try shell build + unzip: https://queue.taskcluster.net/v1/task/Jg8FidEIQKe0ZpsYSo-kVw/runs/0/artifacts/public/build/target.jsshell.zip
2. Download the following JS file: https://pastebin.mozilla.org/9084636
3. Run:

$ while $js -e "print(Date.now())" -f test.js; do :; done

If I run this in 5 terminals at the same time, I get it to hang in one of them within 10 seconds or so. With rr record --chaos I got it to repro once out of thousands of runs.

[jandem]

That's the target.jsshell.zip file for this build, in case you want to check what code you're running:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=96242b2294ad7fdbdc90a1272fd0de881a15edc7&filter-searchStr=Linux%20x64%20debug%20build-linux64%2Fdebug%20(B)&selectedJob=176772603

[jandem]

It's a tricky race because it involves 3 threads:

1. The main thread wants to stop all helper threads, so it has a |while (there-are-tasks) wait-on-condvar| [0].
2. Thread 2 is a helper thread doing off-thread parsing, it sees an asm.js module, starts a compilation task and blocks on that.
3. Thread 3 is a helper thread doing the asm.js compilation.

Then what happens is this: thread 3 tells thread 2 it's done compiling asm.js. Then thread 2 gets scheduled and quickly finishes parsing, notifying the condition var thread 1 is waiting on. However thread 3 is still active so thread 1 sees there is an active task still and starts to wait() again. It can wait forever because thread 3 never notifies it - it only notifies thread 2.

[0] https://searchfox.org/mozilla-central/rev/ce9ff94ffed34dc17ec0bfa406156d489eaa8ee1/js/src/vm/HelperThreads.cpp#1050-1057

[rocallahan]

I assume thread 3 transitions to the idle state soon after it has notified thread 2, so the race is rare because that window is narrow?

[jandem]

I assume thread 3 transitions to the idle state soon after it has notified thread 2, so the race is rare because that window is narrow?

Yeah. And in the meantime thread 2 has to wake up and finish its ParseTask and wake up thread 1, and thread 1 has to do a loop iteration.

But still, on my system it's easy to repro without rr, as long as I run multiple processes in parallel.

[rocallahan]

Are any priorities set on these threads normally?

On a multicore system outside rr, I guess the race occurs if 3 happens to be descheduled after notifying thread 2. Meanwhile threads 1 and 2 keep running and you reach the deadlock.

In rr without chaos mode, thread 1 and 2 will block. Thread 3 will run, notify thread 2, but it is very likely it won't be descheduled until it has reached the idle state, and depending on the code it might never be descheduled until it has reached the idle state.

In rr with chaos mode, we use randomized timeslice intervals and we assign random priorities (0 or 1) to threads; no low-priority thread will be scheduled while any high-priority thread is runnable. It seems like chaos mode's best chance to reproduce the bug is if thread 3 is low-priority and threads 1 and 2 are high-priority; then threads 1 and 2 will block, and thread 3 will run. If thread 3's timelice expires in the target window, then threads 1 and 2 will complete their work before we allow thread 3 to continue. Apparently the probability of thread 3's timeslice expiring in the right window is still very low.

After thread 3 does a FUTEX_WAKE to notify thread 2, thread 2 is runnable and since it's higher priority than thread 3, we should really deschedule thread 3 immediately and run thread 2. I thought we were doing this but I can't find the code for it so I guess I was imagining things :-). Allowing FUTEX_WAKE to immediately yield (in chaos mode) might make this bug a lot easier to reproduce. I'll try it.

[jandem]

Are any priorities set on these threads normally?

I don't think so

Allowing FUTEX_WAKE to immediately yield (in chaos mode) might make this bug a lot easier to reproduce.

Yes that makes sense.

[rocallahan]

OK, edb1485 should fix this. In my testing, I was unable to reproduce your JS bug with chaos mode before the fix, but after the fix I can reproduce it within a couple of hundred test runs.

[rocallahan]

One interesting question is whether we should extend this to write, sendmsg and other syscalls that could potentially allow other blocked syscalls in higher-priority threads to proceed. Even read could allow a thread blocked writing to a full pipe to continue. The overhead of doing that could be bad.

Maybe for a fixed time interval, e.g. 3s every 30s, we could turn off all syscall buffering. That would increase the number of runs to hit the bug by more than a factor of 10, though --- more, because during those 3s you'd get a lot less work done than during 3s of normal, syscall-buffered execution.

[rocallahan]

Another option would be to have rr detect when a task is reading from a file descriptor connected to writeable file descriptors of other tasks, and mark those writeable file descriptors as non-syscall-buffered in syscallbuf_fds_disabled. That could be rather complex, although getting it work for pipe and socketpair would probably not be hard.

[rocallahan]

Handling blocking syscalls like select and epoll would be really hard, and realistic applications probably use those for their event loops...

[rocallahan]

Possibly instead of our current waitpid poll to detect if a task has unblocked, we could use a SIGCHLD handler to notify rr directly, and if that's a high-priority task that rr wants to preempt a running low-priority task, it could interrupt the low-priority task. However, that might take too long to catch bugs where the low-priority task needs to be interrupted immediately after it unblocks the high-priority task.