none/tests/pth_2sig hangs at exit with 100% cpu utilization #189
Comments
|
That is really really late in the execution. The guest has exited and I expect that Valgrind is cleaning up - closing files and pipes created for gdb. Does running with -v -v -v -v -d -d -d -d add anything of use at the end? I don't see this hang on 13.0 and 13.1 in a VirtualBox x86 VM. |
|
It adds: |
|
The |
|
Another unexplored dark corner. The reads and writes are from the scheduler, ML_(sema_up) and ML_(sema_down), reading and writing the global sema_char which increments from 'A' to 'Z' then wraps. The last log message you get is from m_main.c line 2355 Presumably it is then calling VG_(client_exit)( VG_(threads)[tid].os_state.exitcode ); on line 2373 with exit code 0 That just calls exit_wrk with gdbserver_call_allowed False so it doesn't call any of the gdbserver functions. I was thinking that it might be stuck in VG_(gdbserver_exit) but that doesn't appear to be the case. That just does a syscall exit. |
|
Looking at the code Does increasing the 2 second sleep change anything? If you change this to do you see this loop running as it hangs? What ought to happen parent creates 10 threads that all suspend What I'm thinking is that the threads may be created but not started, and the TERM signals being sent to these non-started threads rather than the parent main thread. If all 20 kill()s in the child fail, that would mean that the child exits and the parent ends up in the pause(). Does it change things if SIGTERM is blocked for the parent threads, like this |
|
The first change has little effect -- you see all the messages, but then it hangs even harder than before, you can see the ctrl-T output. There's no way to kill it -- ssh'ing to the machine gets me the login banner, but then can't get to a shell, and of course dropping the ssh connection it was started on doesn't help. Time to hard power-cycle the system. |
|
Single-click of the power button initiates a shutdown, which times out after 90s, and then it attempts to go to single-user mode, but ends up powering off instead (at least on this hardware) The console is non-responsive except for displaying the messages. If one distilled what's happening in valgrind/pth_2sig one would have a pretty effective DoS attack from userland. |
|
For the hang, one thing that sometimes works for me is ssh machine ps to get the rogue process pid ssh machine kill -9 pid For the problem it looks like the client code is doing what it claims. The child is signalling the parent and I presume then calling exit() (unless it is stuck in kill). The parent is getting the signal and at least terminating the while/printf/sleep loop. But the Valgrind scheduler is still running so something is refusing to die. Issue #188 188 has somewhat similar symptoms, except that it is during execution rather than at cleanup. |
|
I just tried self-hosting on 13.0 and amd64 Not sure why there are 5 SIGTERM messages. They all have the callstack of the main thread rather than the 10 slavethreads. Gives some indication of what the exit path callstack looks lik. |
|
And for me on i386 running with -d I get (with some heavy editing to remove aspace and gdbserver messages) What do you get, in particular the "last one standing" messages? |
I don't see the backtrace that you got. This was |
|
Hmm. Looks like none of the child signals are being delivered. The child then exits, leaving the parent stuck in the pause(). Does increasing the sleep() time or the number in the for / kill loop change anything? |
|
If I make this change: it all seems to work OK. |
|
How does that work? The child pause() will certainly allow the parent to run and receive the SIGTERM. But then how does the child get out of the pause()? Do you need to hit ctrl-c? It does look like this is more a testcase problem than a Valgrind problem. |
|
No, no ctrl-C necessary. Beats me how it works. I'll try something different and see what happens. |
|
It feels to me as though doing anything that might cause a yield in the It's still disconcerting, though, that in the original case it can cause the system to lock up so tight. |
|
commit a415120 (HEAD -> master, origin/master, origin/HEAD) |
|
I'm very happy not having the tests hang up here every time I run them, but there's still the outstanding question of why it's fine if you run the original pth_2sig program without valgrind, but with it it does not function correctly. When not running under valgrind the (new) pth_2sig truss output looks like (ignoring startup) so after the sleep for 2s, the first |
It's because "sleep()" is not a reliable synchronisation mechanism. In this context it's saying "let's hope that the other process has done something by the end of the sleep()". There's no guarantee that will happen. Increasing the sleep may make it more likely, but it's never certain. In my previous job I had one project where we were simulating Intel CPU cores which would take up to 700Gbytes of RAM and the Linux kernel for some reason decided that it wanted to do a NUMA migration. The process was then suspended off-CPU for something like 10 hours. An extreme example, but it shows that CPU scheduling can't be taken for granted. On top of that the Valgrind scheduler is fairly basic. In this case there are two processes which will be scheduled by the FreeBSD kernel. Each of these is scheduled by Valgrind, in particular the 10+1 threads of the parent process. I don't know exactly what can cause a thread to yield, certainly a yielding syscall, but I don't think that the Valgrind scheduler implements things like pre-emption and priority. All that to say that for guest applications that go not use guaranteed synchronization the order of execution can be different under Valgrind. I don't think that Valgrind should be behaving badly like that though. I think that there is a real problem with the scheduler when there are incomplete syscalls. |
|
I've just been looking at where SfYieldAfter gets set. One difference that I see with Linux is that when Linux forks/creates a thread the check is
before setting the yeild fld On FreeBSD, fork just checks SUCCESS and thr_create just checks sr_isError(res) SUCCESS means that the syscall is complete and there is not an error What would happen if the error flag is set but the return code is non-zero? Is that possible? |
|
Could you try this diff and then rerun under Valgrind with full bells and whistles logging ../../vg-in-place --tool=none --trace-sched=yes -v -v -v -v -d -d -d -d --vgdb=no --trace-syscalls=yes --trace-signals=yes and see if anything extra gets printed? Only -d output gets written immediately, I think all other output gets buffered and when Valgrind hangs there may still be stuff in the buffer. |
|
OK, I think I correctly decoded what markdown did to the diff output (just disabling the if condition with |
|
That trace was with the original pth_2sig.c source so that it hung. This one is with the nanosleep() present, so it exits normally. Same hack with |
|
Looking at that change again, didn't you want the test to be true to always flush the output and clear the buffer? |
|
Yes, my mistake with the 'if'. Does this patch help |
|
No joy with that patch either. Current state is: (where it's running with the older pth_2sig.c that does not do the nanosleep(), and it does do the buffer flush every time in m_libcprint.c) |
|
There are two processes. 43050 which runs to completion. 43049 which gets stuck, and that's the parent. The last thing that 43049 says is 1 --43049-- SCHED[1]: releasing lock (VG_(client_syscall)[async]) -> VgTs_WaitSys I see something very similar with none/tests/tls in FreeBSD 13.1 amd64: --72132-- SCHED[13]: releasing lock (VG_(client_syscall)[async]) -> VgTs_WaitSys (issue #188) After that message there are a couple of functions that just lead to ML_(sema_up)(&p->sema, False); That seems to be working OK. Back to the last message. It comes from VG_(client_syscall). What is supposed to happen is
There are now two possibilities 2b/ The syscall is interrupted. We go to async_signalhandler. Again I'd expect an "acquired lock" message. |
|
Could you try another test, with the handing testcase?
then Do you see a sequence similar to the ast/pipelk/piperd that I see for #188 ? |
|
Sure -- I'm assuming you want the pth_2sig without the |
|
Great, that does look similar. |
|
Hi Nick Is your 13.1 i386 system single core? If so, and if it is a VM, can you add a second core to the VM? I managed to "fix" the issue I was having with #188 13.1 amd64 by changing the VirtualBox VM to use 2 cores. |
|
It's real hardware, not a VM, and it's single-threaded: |
|
In that case I don't have a solution. Hopefully this will get fixed soonish in a FreeBSD update. I did try fiddling with a few sysctls but none seemed to affect the hangs. |
Do "they" agree that there's something that needs to be fixed in FreeBSD? |
|
Mark Johnston (a member of the core team) on the freebsd-hackers mailing list did say '"procstat -kk " might help to reveal what's going on, I'll open a freebsd bugzilla item if i don't get an acknowledgement in the next day or two. |
|
75137 100127 memcheck-x86-freebs - mi_switch+0x143 ast+0x267 __stop_set_sysinit_set+0xe616dc91 but 75138, the 2nd process, doesn't show up anywhere, and a |
|
That's interesting. It's similar but not identical to what I saw, If you run |
|
I tried again, and left it a lot longer, and there were no changes, but it seems to have captured the 2nd process as I killed it off... |
|
I just logged a bug |
I suspect this is FreeBSD specific.
I've attached the output with syscall and signal traces turned on. It's 100% reproducible.
Code is at 2dad922.
pth_2sig-hangs.txt
The text was updated successfully, but these errors were encountered: