Re: Hang ast / pipelk / piperd

On 5/27/22 22:13, Paul Floyd wrote:
>
> Hi
>
> I'm debugging two issues with Valgrind on FreeBSD 13.1 and 14, one on 
> amd64 and one on i386.
>
...
> |Both hangs seem quite sensitive to timing - in both cases adding or 
> changing nanosleep times seem to make them no longer hang. |
> |Adding debug statements to Valgrind can also change the behaviour 
> (and is also unsafe when not holding the scheduler lock). Does this 
> look like a kernel bug? |

thunderbird munged the formatting when I switched to plain text so I'm 
sending again.

One important detail I missed out. Why is Valgrind releasing the 
scheduler lock?|


To make a client syscall. This needs to be done in "client-like" 
circumstances - specifically, with the client signal mask (rather than 
the Valgrind mask, which is to mask all signals so that Valgrind has 
full control).|

Two things can happen with a client syscall.|

1/ it succeeds, and Valgrind will re-acquire the lock and continue.|

2/ it gets interrupted, Valgrind re-acquires the lock, does a load of 
stuff to fixup the guest state and take the appropriate action (restart, 
return EINTR, save carry etc).|

I did think that 2/ might be prone to get into an infinite loop, 
especially with restart. But I don't see anything like that in the 
Valgrind logs.|

PJF thread 14 making a client nanosleep syscall
|SYSCALL[5379,14](240) sys_nanosleep ( 0x200890, 0x0 ) --> [async] ...

PJF -thread 14 releases the scheduler lock
--5379--   SCHED[14]: releasing lock (VG_(client_syscall)[async]) -> 
VgTs_WaitSys

PJF thread 2 acquires the scheduler lock
--5379--   SCHED[2]:  acquired lock (VG_(client_syscall)[async])

PJF thread 2 return from nanosleep
SYSCALL[5379,2](240) ... [async] --> Success(0x0)

PJF thread 2 making a client write syscall
SYSCALL[5379,2](  4) sys_write ( 1, 0x4ea9000, 48 ) --> [async] ...
PJF thread 2 releases the scheduler lock

--5379--   SCHED[2]: releasing lock (VG_(client_syscall)[async]) -> 
VgTs_WaitSys

PJF this is the thread 2 printf from syscall write
tls_ptr: case "race" has mismatch: *ip=8 here=4

PJF thread 2 acquires the scheduler lock
--5379--   SCHED[2]:  acquired lock (VG_(client_syscall)[async])

PJF thread 2 return from write (30 bytes written)
SYSCALL[5379,2](  4) ... [async] --> Success(0x30)

PJF thread 2 making a client nanosleep syscall
SYSCALL[5379,2](240) sys_nanosleep ( 0x200890, 0x0 ) --> [async] ...

PJF thread 2 releases the scheduler lock
--5379--   SCHED[2]: releasing lock (VG_(client_syscall)[async]) -> 
VgTs_WaitSys


And that's it, it hangs making the client nanosleep syscall.


Under gdb I see (and this is quite variable)

(gdb) info thread
   Id   Target Id                 Frame
* 1    LWP 100073 of process 861 vgModuleLocal_do_syscall_for_client_WRK 
() at m_syswrap/syscall-amd64-freebsd.S:135
   2    LWP 100215 of process 861 
vgModuleLocal_do_syscall_for_client_WRK () at 
m_syswrap/syscall-amd64-freebsd.S:135
   3    LWP 100216 of process 861 0x00000000380bffac in do_syscall_WRK ()
   4    LWP 100217 of process 861 0x00000000380bffac in do_syscall_WRK ()
   5    LWP 100218 of process 861 0x00000000380bffac in do_syscall_WRK ()
   6    LWP 100219 of process 861 0x00000000380bffac in do_syscall_WRK ()
   7    LWP 100220 of process 861 0x00000000380bffac in do_syscall_WRK ()
   8    LWP 100221 of process 861 0x00000000380bffac in do_syscall_WRK ()
   9    LWP 100222 of process 861 0x00000000380bffac in do_syscall_WRK ()
   10   LWP 100223 of process 861 0x00000000380bffac in do_syscall_WRK ()
   11   LWP 100224 of process 861 0x00000000380bffac in do_syscall_WRK ()
   12   LWP 100225 of process 861 0x00000000380bffac in do_syscall_WRK ()
   13   LWP 100226 of process 861 0x00000000380bffac in do_syscall_WRK ()
   14   LWP 100227 of process 861 0x00000000380bffac in do_syscall_WRK ()
   15   LWP 100228 of process 861 0x00000000380bffac in do_syscall_WRK ()

do_syscall_WRK is the syscall interface for the Valgrind host, and that 
will be the threads waiting for the lock.

Thread 1 and 2 are in do_syscall_for_client, the interface for guest
syscalls. Thread 1 is doing a _umtx_op syscall, for the pthread_join. 
Thrread 2 is doing a nanosleep. These are blocking syscalls so they
release the lock before making the syscall to allow other threads to
execute.

I think that in the snapshot above, the lock is released and one
of threads 3 to 15 should be obtaining the lock and running.

That's where the kernel context switch / AST seems to be going wrong.

I don't see anything particularly wrong on the Valgrind side.

Any ideas what I can do to see why the context switch is hanging?


A+
Paul