Repository navigation
Assertion failure: Replaying SCHED': expecting tracee signal or trap, but instead at [FATAL /home/ANT.AMAZON.COM/kdnilsen/github/rr/src/Task.cc:3024:detect_syscall_arch()] #3030
Description
Activity
I assume this is reproducible on the same trace?
Can you attach gdb to rr (not following the instructions at the bottom, just with gdb attach )?
What is
regs().ip()in theTask::detect_syscall_archframe?Thanks for your very responsive help with this. I unfortunately lost access to the host that originally exhibited this problem and it has taken me several days to get a new host set up for rr testing. I was thinking my new host might not replicate the problem because other team members have not seen this problem when running similar workloads.
Fortunately (?), the problem still manifests on my new host (with a new recording).
I'm not quite sure how to get the information you are requesting. I tried starting up "gdb rr", then set breakpoint in Task::detect_syscall_arch(), then I "run replay". It never got to my breakpoint, though it did crash with the same error messages quoted above.
Actually, on more careful scrutiny, the new crash trigger is slightly different than the one quoted above:
[FATAL /home/ubuntu/Devel/kdnilsen/github/rr/src/ReplaySession.cc:787:guard_unexpected_signal()]
(task 163197 (rec:148015) at time 3159639)
-> Assertionfalse' failed to hold. Replay got unrecorded signal SIGSEGV while awaiting signal {signo:SIGSEGV,errno:SUCCESS,code:SEGV_ACCERR,addr:0x7fcfc9376000} Tail of trace dump: { real_time:31064.494270 global_time:3159619, event:SCHED' tid:147985, ticks:2758089
rax:0x15fc4c rbx:0x1fffce rcx:0x1fffce rdx:0x15fc4b rsi:0x1fffce rdi:0x7fc3b2000190 rbp:0x7fcfc4427760 rsp:0x7fcfc4427760 r8:0x0 r9:0x7fcfc00f6520 r10:0x0 r11:0x246 r12:0x3fff9c r13:0x7fc3b3000000 r14:0x7fcfc6cde2c0 r15:0x7fcfc4427fc0 rip:0x7fcfc757c441 eflags:0x202 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fcfc4428700 gs_base:0x0
}
...
=== Start rr backtrace:
/usr/local/bin/rr(_ZN2rr13dump_rr_stackEv+0x5d)[0x555555acec51]
/usr/local/bin/rr(_ZN2rr9GdbServer15emergency_debugEPNS_4TaskE+0x1a6)[0x5555558daee8]
/usr/local/bin/rr(+0x3bf76e)[0x55555591376e]
/usr/local/bin/rr(_ZN2rr21EmergencyDebugOstreamD1Ev+0x66)[0x5555559139f6]
/usr/local/bin/rr(+0x4b563f)[0x555555a0963f]
/usr/local/bin/rr(_ZN2rr13ReplaySession20emulate_async_signalEPNS_10ReplayTaskERKNS0_15StepConstraintsElNS_15remote_code_ptrE+0x105f)[0x555555a0ac2f]
/usr/local/bin/rr(_ZN2rr13ReplaySession18try_one_trace_stepEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0x17a)[0x555555a0d852]
/usr/local/bin/rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x1d7)[0x555555a0ee59]
/usr/local/bin/rr(_ZN2rr14ReplayTimeline19replay_step_forwardENS_10RunCommandEl+0x10a)[0x555555a2e6ee]
/usr/local/bin/rr(_ZN2rr9GdbServer14debug_one_stepERNS_10GdbRequestE+0x5a2)[0x5555558d7d2c]
/usr/local/bin/rr(_ZN2rr9GdbServer12serve_replayERKNS0_15ConnectionFlagsE+0x54f)[0x5555558d9f8f]
/usr/local/bin/rr(+0x4af8be)[0x555555a038be]
/usr/local/bin/rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x407)[0x555555a04383]
/usr/local/bin/rr(main+0x27d)[0x555555aeaa22]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf3)[0x7ffff794f0b3]
/usr/local/bin/rr(_start+0x2e)[0x5555558306ce]
=== End rr backtrace
Launch gdb with
gdb '-l' '10000' '-ex' 'set sysroot /' '-ex' 'target extended-remote 127.0.0.1:32125' /home/ubuntu/Devel/kdnilsen/gitfarm/borrow-from-old-gen/build/linux-x86_64-server-slowdebug/jdk/bin/javaOk, same first question, does repeatedly
rr replay -aing the same trace crash in the same way?A second attempt at replay crashes with very similar, but slightly different reprot:
[361.370s][info][gc,start ] GC(0) Concurrent remembered set scanning
[361.380s][info][gc ] GC(0) Concurrent remembered set scanning 10.014ms
[361.382s][info][gc,start ] GC(0) Concurrent marking roots
[361.383s][info][gc,task ] GC(0) Using 6 of 6 workers for concurrent marking roots
[FATAL /home/ubuntu/Devel/kdnilsen/github/rr/src/ReplaySession.cc:787:guard_unexpected_signal()]
(task 163778 (rec:148015) at time 3159639)
-> Assertionfalse' failed to hold. Replay got unrecorded signal SIGSEGV while awaiting signal {signo:SIGSEGV,errno:SUCCESS,code:SEGV_ACCERR,addr:0x7fcfc9376000} Tail of trace dump: { real_time:31064.494270 global_time:3159619, event:SCHED' tid:147985, ticks:2758089
rax:0x15fc4c rbx:0x1fffce rcx:0x1fffce rdx:0x15fc4b rsi:0x1fffce rdi:0x7fc3b2000190 rbp:0x7fcfc4427760 rsp:0x7fcfc4427760 r8:0x0 r9:0x7fcfc00f6520 r10:0x0 r11:0x246 r12:0x3fff9c r13:0x7fc3b3000000 r14:0x7fcfc6cde2c0 r15:0x7fcfc4427fc0 rip:0x7fcfc757c441 eflags:0x202 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fcfc4428700 gs_base:0x0
}
...
{
real_time:31064.496336 global_time:3159640, event:`SYSCALL: futex' (state:EXITING_SYSCALL) tid:147980, ticks:4948681
rax:0x0 rbx:0x7fcfc804b892 rcx:0xffffffffffffffff rdx:0x2 rsi:0x80 rdi:0x7fcfc05a6ac8 rbp:0x7fcfc5331a00 rsp:0x7fcfc53319b8 r8:0x0 r9:0x1 r10:0x0 r11:0x246 r12:0x7fcfc6cde16e r13:0x7fcfc6cde16f r14:0x7fcfc6cde2c0 r15:0x7fcfc5331fc0 rip:0x7fcfc910f110 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x7fcfc5332700 gs_base:0x0
}
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackEv+0x5d)[0x5607acf54c51]
rr(_ZN2rr9GdbServer15emergency_debugEPNS_4TaskE+0x1a6)[0x5607acd60ee8]
rr(+0x3bf76e)[0x5607acd9976e]
rr(_ZN2rr21EmergencyDebugOstreamD1Ev+0x66)[0x5607acd999f6]
rr(+0x4b563f)[0x5607ace8f63f]
rr(_ZN2rr13ReplaySession20emulate_async_signalEPNS_10ReplayTaskERKNS0_15StepConstraintsElNS_15remote_code_ptrE+0x105f)[0x5607ace90c2f]
rr(_ZN2rr13ReplaySession18try_one_trace_stepEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0x17a)[0x5607ace93852]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x1d7)[0x5607ace94e59]
rr(_ZN2rr14ReplayTimeline19replay_step_forwardENS_10RunCommandEl+0x10a)[0x5607aceb46ee]
rr(_ZN2rr9GdbServer14debug_one_stepERNS_10GdbRequestE+0x5a2)[0x5607acd5dd2c]
rr(_ZN2rr9GdbServer12serve_replayERKNS0_15ConnectionFlagsE+0x54f)[0x5607acd5ff8f]
rr(+0x4af8be)[0x5607ace898be]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x407)[0x5607ace8a383]
rr(main+0x27d)[0x5607acf70a22]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf3)[0x7fcc8b1110b3]
rr(_start+0x2e)[0x5607accb66ce]
=== End rr backtrace
Launch gdb with
gdb '-l' '10000' '-ex' 'set sysroot /' '-ex' 'target extended-remote 127.0.0.1:32706' /home/ubuntu/Devel/kdnilsen/gitfarm/borrow-from-old-gen/build/linux-x86_64-server-slowdebug/jdk/bin/javaAlright. Let's call that the same crash. Can you
rr dump -p -m -b > some_file, compress some_file, and upload it?Even compressed, the file is 1603MB! It won't attach. Is there a better way to approach this?
Ok, how about the last 10k lines of the log then?
Thanks for your efforts on this.
Ah, sorry, maybe something like
rr dump -p -m -b ~/.local/share/rr/latest-trace 3155000-3160000. I forgot that this crash is in the middle of the trace, not at the very end.Try this.
Thanks. The thread in question has two events in fairly close succession
{ real_time:31064.496213 global_time:3159638, event:`INSTRUCTION_TRAP' tid:148015, ticks:468836924 rax:0x16 rbx:0x756e6547 rcx:0x6c65746e rdx:0x49656e69 rsi:0x7fcfc05a65c0 rdi:0x7fc28a7f2f20 rbp:0x7fc28a7f3030 rsp:0x7fc28a7f3010 r8:0x0 r9:0x1 r10:0x0 r11:0x246 r12:0x7fc3ba6130f0 r13:0x0 r14:0x660 r15:0x7fcfc05a6150 rip:0x7fcfc73bccbb eflags:0x10246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fc28a7f7700 gs_base:0x0 } { real_time:31064.496325 global_time:3159639, event:`SCHED' tid:148015, ticks:468837077 rax:0x7fc3ba615180 rbx:0x0 rcx:0x7fc3ba613130 rdx:0xcd1 rsi:0x7fc3ba613130 rdi:0x0 rbp:0x1330 rsp:0x7fc28a7f6200 r8:0xbef r9:0x6f r10:0x7fcfc931f000 r11:0xcd0 r12:0x7fc3ba6130f0 r13:0x0 r14:0x660 r15:0x7fcfc05a6150 rip:0x7fcfb8af1b22 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fc28a7f7700 gs_base:0x0 }So first it takes an INSTRUCTION_TRAP event to emulate something like rdtsc or cpuid, then it executes another ~150 conditional branches and takes a SCHED (context switch), and sometime in that narrow window our replay diverges by hitting this unexpected SIGSEGV.
Can you
rr replay -aagain, this time follow the instructions at the bottom about attaching gdb after it crashes (e.g.gdb '-l' '10000' '-ex' 'set sysroot /' '-ex' 'target extended-remote 127.0.0.1:32706' /home/ubuntu/Devel/kdnilsen/gitfarm/borrow-from-old-gen/build/linux-x86_64-server-slowdebug/jdk/bin/javafrom your previous error, but note that the exact command will be slightly different when you run it this time), and thendisas 0x7fcfc73bccbbanddisas 0x7fcfb8af1b22(the %rip values at those two events) so we can get some idea what the program is doing here?I'm not sure if I did exactly what you wanted, but here is what I'm seeing:
(No debugging symbols found in system-supplied DSO at 0x6fffd000) Reading in symbols for /home/ubuntu/Devel/kdnilsen/gitfarm/borrow-from-old-gen/src/hotspot/cpu/x86/macroAssembler_x86.cpp...done. 0x00007fcfc7cd8750 in MacroAssembler::debug64 (msg=0x7fcfc88a42c8 "Attempting to adjust pc to skip safepoint poll but the return point is not what we expected", pc=1, regs=0x0) at /home/ubuntu/Devel/kdnilsen/gitfarm/borrow-from-old-gen/src/hotspot/cpu/x86/macroAssembler_x86.cpp:863 863 fatal("DEBUG MESSAGE: %s", msg); Current language: auto The current source language is "auto; currently c++". (gdb) disas 0x7fcfc73bccbb Reading in symbols for /home/ubuntu/Devel/kdnilsen/gitfarm/borrow-from-old-gen/src/hotspot/os/linux/attachListener_linux.cpp...done. Dump of assembler code for function OrderAccess::cross_modify_fence_impl(): 0x00007fcfc73bcc94 <+0>: endbr64 0x00007fcfc73bcc98 <+4>: push %rbp 0x00007fcfc73bcc99 <+5>: mov %rsp,%rbp 0x00007fcfc73bcc9c <+8>: push %rbx 0x00007fcfc73bcc9d <+9>: sub $0x18,%rsp 0x00007fcfc73bcca1 <+13>: callq 0x7fcfc73bcc42 <VM_Version::supports_serialize()> 0x00007fcfc73bcca6 <+18>: test %al,%al 0x00007fcfc73bcca8 <+20>: je 0x7fcfc73bccaf <OrderAccess::cross_modify_fence_impl()+27> 0x00007fcfc73bccaa <+22>: (bad) 0x00007fcfc73bccac <+24>: callq 0x7fd00d02dc9c 0x00007fcfc73bccb1 <+29>: in (%dx),%al 0x00007fcfc73bccb2 <+30>: add %al,(%rax) 0x00007fcfc73bccb4 <+32>: add %al,(%rax) 0x00007fcfc73bccb6 <+34>: mov -0x14(%rbp),%eax 0x00007fcfc73bccb9 <+37>: cpuid 0x00007fcfc73bccbb <+39>: mov %eax,-0x14(%rbp) 0x00007fcfc73bccbe <+42>: nop 0x00007fcfc73bccbf <+43>: add $0x18,%rsp 0x00007fcfc73bccc3 <+47>: pop %rbx 0x00007fcfc73bccc4 <+48>: pop %rbp 0x00007fcfc73bccc5 <+49>: retq End of assembler dump. (gdb) disas 0x7fcfb8af1b22 No function contains specified address. (gdb)Try
disas 0x7fcfb8af1b22-0x80,+0x100?We're in the hotspot JIT here, I guess 0x7fcfb8af1b22 is probably JITted code?
I was just thinking about that.
yes. probably.The other question of interest here is what is the instruction that's actually faulting? (i.e. what does
info regsanddisas $rip-20,$rip+20say)(gdb) info registers
rax 0x7fcfc9376000 140530410807296
rbx 0x7fcfb8af1b23 140530133441315
rcx 0x1 1
rdx 0x0 0
rsi 0x1 1
rdi 0x7fcfc88a42c8 140530399462088
rbp 0x7fc28a7f56d0 0x7fc28a7f56d0
rsp 0x7fc28a7f5690 0x7fc28a7f5690
r8 0x0 0
r9 0x1 1
r10 0x0 0
r11 0x246 582
r12 0x7fc3ba6130f0 140478622281968
r13 0x0 0
r14 0x660 1632
r15 0x7fcfc05a6150 140530262106448
rip 0x7fcfc7cd8750 0x7fcfc7cd8750 <MacroAssembler::debug64(char*, long, long*)+212>
eflags 0x10246 [ PF ZF IF RF ]
cs 0x33 51
ss 0x2b 43
ds 0x0 0
es 0x0 0
fs 0x0 0
gs 0x0 0
(gdb) disas $rip-20, $rip+20
Dump of assembler code from 0x7fcfc7cd873c to 0x7fcfc7cd8764:
0x00007fcfc7cd873c <MacroAssembler::debug64(char*, long, long*)+192>: callq 0x7fcfc7cd8784 <MacroAssembler::print_state64(long, long*)>
0x00007fcfc7cd8741 <MacroAssembler::debug64(char*, long, long*)+197>: Reading in symbols for /home/ubuntu/Devel/kdnilsen/gitfarm/borrow-from-old-gen/src/hotspot/os/linux/os_linux.cpp...done.
callq 0x7fcfc7e5c168 <breakpoint()>
0x00007fcfc7cd8746 <MacroAssembler::debug64(char*, long, long*)+202>: lea 0x132135b(%rip),%rax # 0x7fcfc8ff9aa8 <g_assert_poison>
0x00007fcfc7cd874d <MacroAssembler::debug64(char*, long, long*)+209>: mov (%rax),%rax
=> 0x00007fcfc7cd8750 <MacroAssembler::debug64(char*, long, long*)+212>: movb $0x58,(%rax)
0x00007fcfc7cd8753 <MacroAssembler::debug64(char*, long, long*)+215>: mov -0x28(%rbp),%rax
0x00007fcfc7cd8757 <MacroAssembler::debug64(char*, long, long*)+219>: mov %rax,%r8
0x00007fcfc7cd875a <MacroAssembler::debug64(char*, long, long*)+222>: lea 0xa771d3(%rip),%rcx # 0x7fcfc874f934
0x00007fcfc7cd8761 <MacroAssembler::debug64(char*, long, long*)+229>: mov $0x35f,%edx
End of assembler dump.
(gdb) disas 0x7fcfb8af1b22-0x80,+0x100
Dump of assembler code from 0x7fcfb8af1aa2 to 0x7fcfb8af1ba2:
0x00007fcfb8af1aa2: mov %rdi,%rcx
0x00007fcfb8af1aa5: mov %r12d,%r8d
0x00007fcfb8af1aa8: nop
0x00007fcfb8af1aa9: nop
0x00007fcfb8af1aaa: nop
0x00007fcfb8af1aab: callq 0x7fcfb8aec3e0
0x00007fcfb8af1ab0: mov 0x14(%rsp),%r10d
0x00007fcfb8af1ab5: add %eax,%r10d
0x00007fcfb8af1ab8: mov %rbp,%r12
0x00007fcfb8af1abb: mov 0x38(%r12),%rsi
0x00007fcfb8af1ac0: movzbl 0x30(%r12),%edi
0x00007fcfb8af1ac6: mov 0x24(%r12),%ebx
0x00007fcfb8af1acb: mov 0x4(%rsp),%r11d
0x00007fcfb8af1ad0: add %eax,%r11d
0x00007fcfb8af1ad3: testb $0x1,0x20(%r15)
0x00007fcfb8af1ad8: jne 0x7fcfb8af1e05
0x00007fcfb8af1ade: vmovq %rsi,%xmm0
0x00007fcfb8af1ae3: cmp 0x1c(%rsp),%r11d
0x00007fcfb8af1ae8: jl 0x7fcfb8af1b3a
0x00007fcfb8af1aee: test %rsi,%rsi
0x00007fcfb8af1af1: je 0x7fcfb8af2278
0x00007fcfb8af1af7: test %edi,%edi
0x00007fcfb8af1af9: jne 0x7fcfb8af22b0
0x00007fcfb8af1aff: mov %r10d,0x4(%rsp)
0x00007fcfb8af1b04: mov %r11d,%edx
0x00007fcfb8af1b07: jmpq 0x7fcfb8af1d40
0x00007fcfb8af1b0c: nop
0x00007fcfb8af1b0d: nop
0x00007fcfb8af1b0e: nop
0x00007fcfb8af1b0f: nop
0x00007fcfb8af1b10: mov 0x30(%rsp),%rax
0x00007fcfb8af1b15: mov %r9w,0x10(%rax,%r10,2)
0x00007fcfb8af1b1b: mov 0x390(%r15),%r10
0x00007fcfb8af1b22: test %eax,(%r10)
0x00007fcfb8af1b25: cmp 0x1c(%rsp),%edx
0x00007fcfb8af1b29: jge 0x7fcfb8af1d2a
0x00007fcfb8af1b2f: mov %rax,0x30(%rsp)
0x00007fcfb8af1b34: mov %r8d,%r10d
0x00007fcfb8af1b37: mov %edx,%r11d
0x00007fcfb8af1b3a: nop
0x00007fcfb8af1b3b: nop
0x00007fcfb8af1b3c: nop
0x00007fcfb8af1b3d: nop
0x00007fcfb8af1b3e: nop
0x00007fcfb8af1b3f: nop
0x00007fcfb8af1b40: cmp (%rsp),%r11d
0x00007fcfb8af1b44: jae 0x7fcfb8af1e25
0x00007fcfb8af1b4a: mov 0x28(%rsp),%rcx
0x00007fcfb8af1b4f: movsbl 0x10(%rcx,%r11,1),%r9d
0x00007fcfb8af1b55: mov 0x1c(%rsp),%ebp
0x00007fcfb8af1b59: sub %r11d,%ebp
0x00007fcfb8af1b5c: mov %r10d,%r8d
0x00007fcfb8af1b5f: inc %r8d
0x00007fcfb8af1b62: mov %r11d,%edx
0x00007fcfb8af1b65: inc %edx
0x00007fcfb8af1b67: test %r9d,%r9d
0x00007fcfb8af1b6a: jl 0x7fcfb8af1be8
0x00007fcfb8af1b70: cmp 0x38(%rsp),%r10d
0x00007fcfb8af1b75: jge 0x7fcfb8af1c92
0x00007fcfb8af1b7b: nop
0x00007fcfb8af1b7c: nop
0x00007fcfb8af1b7d: nop
0x00007fcfb8af1b7e: nop
0x00007fcfb8af1b7f: nop
0x00007fcfb8af1b80: cmp 0x10(%rsp),%r10d
0x00007fcfb8af1b85: jb 0x7fcfb8af1b10
0x00007fcfb8af1b87: movzwl %r9w,%r9d
0x00007fcfb8af1b8b: mov $0xffffffe4,%esi
0x00007fcfb8af1b90: mov %r12,%rbp
0x00007fcfb8af1b93: mov 0x8(%rsp),%r12
0x00007fcfb8af1b98: mov %r12,(%rsp)
0x00007fcfb8af1b9c: rex.W pushq 0x28(%rsp)
0x00007fcfb8af1ba1: rex.W popq 0x8(%rsp)
End of assembler dump.
(gdb)0x00007fcfc7cd8746 <MacroAssembler::debug64(char*, long, long*)+202>: lea 0x132135b(%rip),%rax # 0x7fcfc8ff9aa8 <g_assert_poison>
0x00007fcfc7cd874d <MacroAssembler::debug64(char*, long, long*)+209>: mov (%rax),%rax
=> 0x00007fcfc7cd8750 <MacroAssembler::debug64(char*, long, long*)+212>: movb $0x58,(%rax)
0x00007fcfc7cd8753 <MacroAssembler::debug64(char*, long, long*)+215>: mov -0x28(%rbp),%raxThis sequence sure looks like TOUCH_ASSERT_POISON from the hotspot source code. What does
bthere output?Reading in symbols for /home/ubuntu/Devel/kdnilsen/gitfarm/borrow-from-old-gen/src/hotspot/cpu/x86/macroAssembler_x86.cpp...done.
0x00007fcfc7cd8750 in MacroAssembler::debug64 (msg=0x7fcfc88a42c8 "Attempting to adjust pc to skip safepoint poll but the return point is not what we expected", pc=1, regs=0x0) at /home/ubuntu/Devel/kdnilsen/gitfarm/borrow-from-old-gen/src/hotspot/cpu/x86/macroAssembler_x86.cpp:863
863 fatal("DEBUG MESSAGE: %s", msg);
Current language: auto
The current source language is "auto; currently c++".
(gdb) bt
#0 0x00007fcfc7cd8750 in MacroAssembler::debug64 (msg=0x7fcfc88a42c8 "Attempting to adjust pc to skip safepoint poll but the return point is not what we expected", pc=1, regs=0x0) at /home/ubuntu/Devel/kdnilsen/gitfarm/borrow-from-old-gen/src/hotspot/cpu/x86/macroAssembler_x86.cpp:863
#1 0x00007fcfb111e4ff in ?? ()
#2 0x000000000000037f in ?? ()
#3 0x0000000000000000 in ?? ()
(gdb)Ok, that assertion looks like it originates from https://github.com/openjdk/jdk/blob/master/src/hotspot/cpu/x86/sharedRuntime_x86_64.cpp#L2981
Hmm, I wonder if the "safepoint poll instruction" this code is examining is 0x7fcfb8af1b22, which we've presumably set a breakpoint on and is going to have a 0xcc in it instead when read back by this code.
Sounds plausible!
The only way I can think of to get around this is to use a hardware breakpoint instead. We wouldn't want to burn one of those scarce hw breakpoints in general so this would have to be an off-by-default
rr replayswitch. That limits its utility a lot unfortunately, but it would solve the reporter's problem (assuming my hypothesis about the cause of the failure is correct, of course).We could do that but they could also just disable that assertion check...
Yeah I suppose that's the alternative here, to recompile hotspot with that assertion removed.
"other team members have not seen this problem when running similar workloads" might also be explained by different compilation options on hotspot here.
Thank you so much for looking at this. For testing purposes, I'm certainly willling to comment out that assertion when I build my test version of hotspot. It might be more difficult to persuade OpenJDK community as a whole to make that change permanent.
I think I may have misspoken about other team members not seeing this problem. After more experimentation, it appears that others have not tried to replay this particular workload. And when I replay different workloads, I also am able to run without encountering this crash.
To be clear, the part you would need to comment out is this block https://github.com/openjdk/jdk/blob/master/src/hotspot/cpu/x86/sharedRuntime_x86_64.cpp#L2960
Please save the trace that's failing (use
rr packto copy in the binaries before you rebuild). We may want to do something to verify my diagnosis.
This is with master, downloaded and built last night. The recording was also captured with master.
[FATAL /home/ANT.AMAZON.COM/kdnilsen/github/rr/src/ReplaySession.cc:667:check_pending_sig() errno: ESRCH]
(task 887345 (rec:461835) at time 19846)
-> Assertion
false' failed to hold. ReplayingSCHED': expecting tracee signal or trap, but instead at[FATAL /home/ANT.AMAZON.COM/kdnilsen/github/rr/src/Task.cc:3024:detect_syscall_arch()] (task 887345 (rec:461835) at time 19846) -> Assertionok' failed to hold.Tail of trace dump:
{
real_time:29163.712516 global_time:19826, event:
SCHED' tid:461839, ticks:1189703 rax:0x7f9f564fe000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f57000000 rdi:0x7f9f56000000 rbp:0x7f988eaf8d60 rsp:0x7f988eaf8d60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f57000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7f988eaf8fc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f988eaf9700 gs_base:0x0 } { real_time:29163.712672 global_time:19827, event:SCHED' tid:461840, ticks:1207102rax:0x7f9f54b00000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f55000000 rdi:0x7f9f54000000 rbp:0x7f988e7f6d60 rsp:0x7f988e7f6d60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f55000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7f988e7f6fc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f988e7f7700 gs_base:0x0
}
{
real_time:29163.712807 global_time:19828, event:
SCHED' tid:461835, ticks:1228739 rax:0x7f9f51c18000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f52000000 rdi:0x7f9f51000000 rbp:0x7fa4c0710d60 rsp:0x7fa4c0710d60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f52000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7fa4c0710fc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fa4c0711700 gs_base:0x0 } { real_time:29163.712944 global_time:19829, event:SCHED' tid:461836, ticks:1165838rax:0x7f9f52a9d000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f53000000 rdi:0x7f9f52000000 rbp:0x7fa4c040ed60 rsp:0x7fa4c040ed60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f53000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7fa4c040efc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fa4c040f700 gs_base:0x0
}
{
real_time:29163.713085 global_time:19830, event:
SCHED' tid:461837, ticks:1208326 rax:0x7f9f53c71000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f54000000 rdi:0x7f9f53000000 rbp:0x7fa4c010cd60 rsp:0x7fa4c010cd60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f54000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7fa4c010cfc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fa4c010d700 gs_base:0x0 } { real_time:29163.713227 global_time:19831, event:SCHED' tid:461838, ticks:1203562rax:0x7f9f559f4000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f56000000 rdi:0x7f9f55000000 rbp:0x7f988edfad60 rsp:0x7f988edfad60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f56000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7f988edfafc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f988edfb700 gs_base:0x0
}
{
real_time:29163.713368 global_time:19832, event:
SCHED' tid:461839, ticks:1191163 rax:0x7f9f56ab2000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f57000000 rdi:0x7f9f56000000 rbp:0x7f988eaf8d60 rsp:0x7f988eaf8d60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f57000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7f988eaf8fc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f988eaf9700 gs_base:0x0 } { real_time:29163.713516 global_time:19833, event:SCHED' tid:461840, ticks:1207542rax:0x7f9f54cb8000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f55000000 rdi:0x7f9f54000000 rbp:0x7f988e7f6d60 rsp:0x7f988e7f6d60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f55000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7f988e7f6fc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f988e7f7700 gs_base:0x0
}
{
real_time:29163.713650 global_time:19834, event:
SCHED' tid:461835, ticks:1229604 rax:0x7f9f51f79000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f52000000 rdi:0x7f9f51000000 rbp:0x7fa4c0710d60 rsp:0x7fa4c0710d60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f52000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7fa4c0710fc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fa4c0711700 gs_base:0x0 } { real_time:29163.713784 global_time:19835, event:SCHED' tid:461836, ticks:1166761rax:0x7f9f52e38000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f53000000 rdi:0x7f9f52000000 rbp:0x7fa4c040ed60 rsp:0x7fa4c040ed60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f53000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7fa4c040efc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fa4c040f700 gs_base:0x0
}
{
real_time:29163.713911 global_time:19836, event:
SCHED' tid:461837, ticks:1208691 rax:0x7f9f53dde000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f54000000 rdi:0x7f9f53000000 rbp:0x7fa4c010cd60 rsp:0x7fa4c010cd60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f54000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7fa4c010cfc0 rip:0x7fa4c3272900 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fa4c010d700 gs_base:0x0 } { real_time:29163.714047 global_time:19837, event:SCHED' tid:461838, ticks:1204633rax:0x7f9f55e23000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f56000000 rdi:0x7f9f55000000 rbp:0x7f988edfad60 rsp:0x7f988edfad60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f56000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7f988edfafc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f988edfb700 gs_base:0x0
}
{
real_time:29163.714178 global_time:19838, event:
SCHED' tid:461839, ticks:1191750 rax:0x7f9f56cfd000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f57000000 rdi:0x7f9f56000000 rbp:0x7f988eaf8d60 rsp:0x7f988eaf8d60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f57000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7f988eaf8fc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f988eaf9700 gs_base:0x0 } { real_time:29163.714317 global_time:19839, event:SCHED' tid:461840, ticks:1207703rax:0x7f9f54d59000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f55000000 rdi:0x7f9f54000000 rbp:0x7f988e7f6d60 rsp:0x7f988e7f6d60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f55000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7f988e7f6fc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f988e7f7700 gs_base:0x0
}
{
real_time:29163.714444 global_time:19840, event:
SCHED' tid:461835, ticks:1229986 rax:0x7f9f570f3000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f58000000 rdi:0x7f9f57000000 rbp:0x7fa4c0710d60 rsp:0x7fa4c0710d60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f58000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7fa4c0710fc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fa4c0711700 gs_base:0x0 } { real_time:29163.714568 global_time:19841, event:SCHED' tid:461836, ticks:1167010rax:0x7f9f52f31000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f53000000 rdi:0x7f9f52000000 rbp:0x7fa4c040ed60 rsp:0x7fa4c040ed60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f53000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7fa4c040efc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fa4c040f700 gs_base:0x0
}
{
real_time:29163.714708 global_time:19842, event:
SCHED' tid:461837, ticks:1210040 rax:0x7f9f5831f000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f59000000 rdi:0x7f9f58000000 rbp:0x7fa4c010cd60 rsp:0x7fa4c010cd60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f59000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7fa4c010cfc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fa4c010d700 gs_base:0x0 } { real_time:29163.714835 global_time:19843, event:SCHED' tid:461838, ticks:1204895rax:0x7f9f55f29000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f56000000 rdi:0x7f9f55000000 rbp:0x7f988edfad60 rsp:0x7f988edfad60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f56000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7f988edfafc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f988edfb700 gs_base:0x0
}
{
real_time:29163.714957 global_time:19844, event:
SCHED' tid:461839, ticks:1191804 rax:0x7f9f56d33000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f57000000 rdi:0x7f9f56000000 rbp:0x7f988eaf8d60 rsp:0x7f988eaf8d60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f57000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7f988eaf8fc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f988eaf9700 gs_base:0x0 } { real_time:29163.715104 global_time:19845, event:SCHED' tid:461840, ticks:1208530rax:0x7f9f59090000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f5a000000 rdi:0x7f9f59000000 rbp:0x7f988e7f6d60 rsp:0x7f988e7f6d60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f5a000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7f988e7f6fc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f988e7f7700 gs_base:0x0
}
{
real_time:29163.715245 global_time:19846, event:
SCHED' tid:461835, ticks:1231386 rax:0x7f9f5766b000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f58000000 rdi:0x7f9f57000000 rbp:0x7fa4c0710d60 rsp:0x7fa4c0710d60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f58000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7fa4c0710fc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fa4c0711700 gs_base:0x0 } { real_time:29163.715380 global_time:19847, event:SCHED' tid:461836, ticks:1167941rax:0x7f9f5a2d0000 rbx:0x1000 rcx:0x0 rdx:0x1000 rsi:0x7f9f5b000000 rdi:0x7f9f5a000000 rbp:0x7fa4c040ed60 rsp:0x7fa4c040ed60 r8:0x0 r9:0xffffffff r10:0x0 r11:0x0 r12:0x7f9f5b000000 r13:0x7fa4c20f816f r14:0x7fa4c20f82c0 r15:0x7fa4c040efc0 rip:0x7fa4c3272907 eflags:0x287 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fa4c040f700 gs_base:0x0
}
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackEv+0x5d)[0x564645d0b913]
rr(_ZN2rr9GdbServer15emergency_debugEPNS_4TaskE+0x1a6)[0x564645b17e08]
rr(+0x3bf68e)[0x564645b5068e]
rr(_ZN2rr21EmergencyDebugOstreamD1Ev+0x66)[0x564645b50916]
rr(_ZN2rr4Task19detect_syscall_archEv+0xb2)[0x564645ccc304]
rr(_ZN2rr13ReplaySession17check_pending_sigEPNS_10ReplayTaskE+0xc9)[0x564645c45b37]
rr(_ZN2rr13ReplaySession20emulate_async_signalEPNS_10ReplayTaskERKNS0_15StepConstraintsElNS_15remote_code_ptrE+0xfc3)[0x564645c4798f]
rr(_ZN2rr13ReplaySession18try_one_trace_stepEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0x17a)[0x564645c4a64e]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x1d7)[0x564645c4bc55]
rr(_ZN2rr14ReplayTimeline19replay_step_forwardENS_10RunCommandEl+0x10a)[0x564645c6b370]
rr(_ZN2rr9GdbServer14debug_one_stepERNS_10GdbRequestE+0x5a2)[0x564645b14c4c]
rr(_ZN2rr9GdbServer12serve_replayERKNS0_15ConnectionFlagsE+0x54f)[0x564645b16eaf]
rr(+0x4af6ba)[0x564645c406ba]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x407)[0x564645c4117f]
rr(main+0x27d)[0x564645d276e2]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf3)[0x7f33757fa0b3]
rr(_start+0x2e)[0x564645a6d6ce]
=== End rr backtrace
Launch gdb with
gdb '-l' '10000' '-ex' 'set sysroot /' '-ex' 'target extended-remote 127.0.0.1:35377' /home/ANT.AMAZON.COM/kdnilsen/.local/share/rr/java-0/mmap_hardlink_4_java