Skip to content
GitLab
Closed
Issue created by Derek Bruening@derekbrueningContributor

nondet ASSERT !TEST(FRAG_LINKED_OUTGOING in receive_pending_signal

This happened once in a -thread_private run:

sig 10 in cache @0x000000005578125e
    1750 1256
sig 10 in gen @0x0000000055662dff inter=0x0000000000000000 next=0x00007fab460f2260
unlinking next frag
unlinking F 0x00007fab460f2260
        unlinked it
pending sig at fcache exit
<Application /work/dr/git/build_x64_dbg_tests/suite/tests/bin/linux.signal_racesys (6891).  Internal Error: DynamoRIO debug check failure: /work/dr/git/src/core/link.c:1783 !TEST(FRAG_LINKED_OUTGOING, f->flags)

#6  0x0000561ad31a5a0a in internal_error (file=0x561ad33c81d4 "/work/dr/git/src/core/link.c", line=1783, 
    expr=0x561ad33cc528 "!TEST(FRAG_LINKED_OUTGOING, f->flags)") at /work/dr/git/src/core/utils.c:174
#7  0x0000561ad31821de in link_fragment_outgoing (dcontext=0x5564b100, f=0x55765d10, new_fragment=false)
    at /work/dr/git/src/core/link.c:1783
#8  0x0000561ad33870d5 in receive_pending_signal (dcontext=0x5564b100) at /work/dr/git/src/core/unix/signal.c:5152
#9  0x0000561ad3192b5f in dispatch_exit_fcache (dcontext=0x5564b100) at /work/dr/git/src/core/dispatch.c:1103
#10 0x0000561ad3192a06 in dispatch_enter_dynamorio (dcontext=0x5564b100) at /work/dr/git/src/core/dispatch.c:913
#11 0x0000561ad318e25e in dispatch (dcontext=0x5564b100) at /work/dr/git/src/core/dispatch.c:154

Frag is not trace or trace head. It is linked in and out. It has a syscall. I don't see how it got re-linked before arriving at receive_pending_signal! The only lazy linking is for coarse at fcache_entry time.

(gdb) p /x f->flags
$2 = 0x1030
(gdb) x/8i f->tag
   0x7fab460f2260 <timer_settime@@GLIBC_2.3.3>: mov    %rcx,%r10
   0x7fab460f2263 <timer_settime@@GLIBC_2.3.3+3>:       movslq 0x4(%rdi),%rdi
   0x7fab460f2267 <timer_settime@@GLIBC_2.3.3+7>:       movslq %esi,%rsi
   0x7fab460f226a <timer_settime@@GLIBC_2.3.3+10>:      mov    $0xdf,%eax
   0x7fab460f226f <timer_settime@@GLIBC_2.3.3+15>:      syscall 
   0x7fab460f2271 <timer_settime@@GLIBC_2.3.3+17>:      cmp    $0xfffffffffffff000,%rax
   0x7fab460f2277 <timer_settime@@GLIBC_2.3.3+23>:      ja     0x7fab460f2280 <timer_settime@@GLIBC_2.3.3+32>
(gdb) x/10i f->start_pc
   0x55780c54:  mov    %rcx,%r10
   0x55780c57:  movslq 0x4(%rdi),%rdi
   0x55780c5b:  movslq %esi,%rsi
   0x55780c5e:  mov    $0xdf,%eax
   0x55780c63:  jmp    0x55780c65
   0x55780c65:  jmpq   0x5578bafc
   0x55780c6a:  syscall 
   0x55780c6c:  jmpq   0x557811a4
   0x55780c71:  stos   %eax,%es:(%rdi)
(gdb) x/4i 0x5578bafc
   0x5578bafc:  addr32 mov %rax,%gs:0x0
   0x5578bb04:  movabs $0x55765d60,%rax
   0x5578bb0e:  jmpq   0x55662dc0
   0x5578bb13:  addr32 mov %rax,%gs:0x0
(gdb) x/4i 0x557811a4
   0x557811a4:  cmp    $0xfffffffffffff000,%rax
   0x557811aa:  ja     0x5578bc3e
   0x557811b0:  jmpq   0x557811c0

Looks like it arrived in fcache_return:

(gdb) x/12i 0x0000000055662dff
   0x55662dff:  mov    %rsp,0x18(%rdi)
   0x55662e03:  mov    %r8,0x40(%rdi)
   0x55662e07:  mov    %r9,0x48(%rdi)
   0x55662e0b:  mov    %r10,0x50(%rdi)
   0x55662e0f:  mov    %r11,0x58(%rdi)
   <...>
   0x55662ec0:  movabs $0x561ad318e206,%r11
   0x55662eca:  callq  *%r11
(gdb) x/8i 0x561ad318e206
   0x561ad318e206 <dispatch>:   push   %rbp

Prior arrived during (or maybe after) nanosleep syscall:
(gdb) x/10i 0x000000005578125e-14
   0x55781250:  mov    $0x23,%eax
   0x55781255:  jmp    0x5578125c
   0x55781257:  jmpq   0x5578bb13
   0x5578125c:  syscall 
   0x5578125e:  nop
   0x5578125f:  jmpq   0x5578bd0d

Could trace_abort() have been called somewhere and it relinked it?

Also just happened on Travis:

https://api.travis-ci.org/jobs/174993121/log.txt?deansi=true

debug-internal-64: 247 tests passed, **** 1 tests failed: ****
	code_api|linux.signal_racesys =>  Application /home/travis/build/DynamoRIO/dynamorio/build_debug-internal-64/suite/tests/bin/linux.signal_racesys (28421).  Internal Error: DynamoRIO debug check failure: /home/travis/build/DynamoRIO/dynamorio/core/link.c:1783 !TEST(FRAG_LINKED_OUTGOING, f-flags) 
68: Test command: /home/travis/build/DynamoRIO/dynamorio/build_debug-internal-64/bin64/drrun "-s" "90" "-quiet" "-debug" "-killpg" "-dr_home" "/home/travis/build/DynamoRIO/dynamorio/install" "-stderr_mask" "0xC" "-dumpcore_mask" "0" "-code_api" "--" "/home/travis/build/DynamoRIO/dynamorio/build_debug-internal-64/suite/tests/bin/linux.signal_racesys"
68: Test timeout computed to be: 600
68: <Application /home/travis/build/DynamoRIO/dynamorio/build_debug-internal-64/suite/tests/bin/linux.signal_racesys (28421).  Internal Error: DynamoRIO debug check failure: /home/travis/build/DynamoRIO/dynamorio/core/link.c:1783 !TEST(FRAG_LINKED_OUTGOING, f->flags)
68: (Error occurred @2180 frags)
68: version 6.2.17116, custom build
68: -no_dynamic_options -code_api -stderr_mask 12 -stack_size 56K -max_elide_jmp 0 -max_elide_call 0 -early_inject -emulate_brk -no_inline_ignored_syscalls -native_exec_default_list '' -no_native_exec_managed_code -no_indcall2direct 
68: 0x0000000049f82bb0 0x00005607e6322c37
68: 0x0000000049f82d00 0x00005607e62ff0a2
68: 0x0000000049f82dc0 0x00005607e6503ad1
68: 0x0000000049f82e00 0x00005607e630fca5
68: 0x0000000049f82e60 0x00005607e630fb69
68: 0x0000000049f82f20 0x00005607e630b1d6
68: 0x0000000049f82ff0 0x0000000049f26ecd
68: 0x00007ffe160b4990 0x000000000040193e
68: 0x00007ffe160b49e0 0x00007ff564ec4f45>
 69/248 Test  #68: code_api|linux.signal_racesys ....................................***Failed  Required regular expression not found.Regex=[^all done
$
]  1.56 sec