Re: kern/54893: New t_ptrace_wait*/resume1 failures since Jan 12

[Andrew Doran <ad%netbsd.org@localhost>]

The following reply was made to PR kern/54893; it has been noted by GNATS.

From: Andrew Doran <ad%netbsd.org@localhost>
To: gnats-bugs%netbsd.org@localhost
Cc: 
Subject: Re: kern/54893: New t_ptrace_wait*/resume1 failures since Jan 12
Date: Tue, 28 Jan 2020 19:02:37 +0000

 It looks to me like there is a race in this test case, which the scheduler
 in -current has exposed, because now if any CPU is idle a new LWP will be
 running within microseconds of _lwp_create().
 
 ===> Working:
 
 child (LID 1)
                 DPRINTF("Before creating new in child\n");
                 FORKEE_ASSERT(_lwp_create(&uc, 0, &lid) == 0);
 
  22139      1 t_ptrace_wait CALL  _lwp_create(0x7f7fff1659d0,0,0x7f7fff1659b8)
  22139      1 t_ptrace_wait RET   _lwp_create 0
 
 child (LID 1):
                 CHILD_TO_PARENT("Message", fds, msg);
 
 child (LID 2)
         the_lwp_id = _lwp_self();
 
         raise(SIGTRAP);
 
         _lwp_exit();
 
  22139      1 t_ptrace_wait CALL  close(5)
  22139      1 t_ptrace_wait RET   close 0
  22139      1 t_ptrace_wait CALL  close(6)
  22139      2 t_ptrace_wait CALL  _lwp_self
  22139      1 t_ptrace_wait RET   close 0
  22139      2 t_ptrace_wait RET   _lwp_self 2
  22139      2 t_ptrace_wait CALL  _lwp_self
  22139      1 t_ptrace_wait CALL  write(7,0x7f7fff1659b3,1)
  22139      2 t_ptrace_wait RET   _lwp_self 2
  22139      1 t_ptrace_wait GIO   fd 7 wrote 1 bytes
        "\M-^"
  22139      2 t_ptrace_wait CALL  _lwp_kill(2,5)
  22139      1 t_ptrace_wait RET   write 1
  22139      2 t_ptrace_wait RET   _lwp_kill 0
  22139      1 t_ptrace_wait CALL  read(4,0x7f7fff1659b3,1)
 
 Look at that, amazin'.  Both LWPs stop here.  Later on in the parent:
 
 parent (LID 1)
 
   5671      1 t_ptrace_wait CALL  read(6,0x7f7fff1659b3,1)
   5671      1 t_ptrace_wait GIO   fd 6 read 1 bytes
        "\M-^"
 
 ===> Failing:
 
  20223      1 t_ptrace_wait CALL  _lwp_create(0x7f7fffb27280,0,0x7f7fffb27268)
  20223      1 t_ptrace_wait RET   _lwp_create 0
  20223      1 t_ptrace_wait CALL  close(5)
  20223      1 t_ptrace_wait RET   close 0
  20223      2 t_ptrace_wait CALL  _lwp_self
  20223      2 t_ptrace_wait RET   _lwp_self 2
  20223      2 t_ptrace_wait CALL  _lwp_self
  20223      2 t_ptrace_wait RET   _lwp_self 2
  20223      2 t_ptrace_wait CALL  _lwp_kill(2,5)
  20223      2 t_ptrace_wait RET   _lwp_kill 0
 
 Oops!
 
 ...
 
 later in the parent:
 
   8999      1 t_ptrace_wait CALL  read(6,0x7f7fffb27263,1)
 
 ^ hangs here