An assertion is triggered on recording tarantool execution #3978
Description
The command rr src/tarantool -e 'print("rr")' leads to an assertion in rr, see below.
rr version 5.7.0
tarantool version: 2.11.5-0-g12a9ceb870c
Ubuntu 24.04.2 LTS
tarantool can be installed as a package (https://www.tarantool.io/en/download/os-installation/ubuntu/) or compiled manually (https://github.com/tarantool/tarantool/).
Full log:
[FATAL ./src/RecordSession.cc:1944:process_syscall_entry()]
(task 2230725 (rec:2230725) at time 3940)
-> Assertion `t->desched_rec() || is_rrcall_notify_syscall_hook_exit_syscall( t->regs().original_syscallno(), t->arch()) || t->ip() == t->vm() ->privileged_traced_syscall_ip() .increment_by_syscall_insn_length(t->arch())' failed to hold. Stashed signal pending on syscall entry when it shouldn't be: {signo:SIGALRM,errno:SUCCESS,code:SI_KERNEL}; regs={ ip:0x79258224f76b args:(0xffffff0000000000,0,0,0x792582248468,0xafffff00000fffff,4611686018427387904) orig_syscall: 24 syscallno: -38 }; last_execution_resume=0x79258224f76b; sig ip=0x79258224f76b
Tail of trace dump:
{
real_time:149235.911211 global_time:3920, event:`SYSCALL: sched_yield' (state:ENTERING_SYSCALL) tid:2230725, ticks:268217801
rax:0xffffffffffffffda rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911224 global_time:3921, event:`SYSCALL: sched_yield' (state:EXITING_SYSCALL) tid:2230725, ticks:268217801
rax:0x0 rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911238 global_time:3922, event:`SYSCALL: sched_yield' (state:ENTERING_SYSCALL) tid:2230725, ticks:268217802
rax:0xffffffffffffffda rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911250 global_time:3923, event:`SYSCALL: sched_yield' (state:EXITING_SYSCALL) tid:2230725, ticks:268217802
rax:0x0 rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911263 global_time:3924, event:`SYSCALL: sched_yield' (state:ENTERING_SYSCALL) tid:2230725, ticks:268217803
rax:0xffffffffffffffda rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911275 global_time:3925, event:`SYSCALL: sched_yield' (state:EXITING_SYSCALL) tid:2230725, ticks:268217803
rax:0x0 rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911289 global_time:3926, event:`SYSCALL: sched_yield' (state:ENTERING_SYSCALL) tid:2230725, ticks:268217804
rax:0xffffffffffffffda rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911300 global_time:3927, event:`SYSCALL: sched_yield' (state:EXITING_SYSCALL) tid:2230725, ticks:268217804
rax:0x0 rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911318 global_time:3928, event:`SYSCALL: sched_yield' (state:ENTERING_SYSCALL) tid:2230725, ticks:268217805
rax:0xffffffffffffffda rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911335 global_time:3929, event:`SYSCALL: sched_yield' (state:EXITING_SYSCALL) tid:2230725, ticks:268217805
rax:0x0 rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911354 global_time:3930, event:`SYSCALL: sched_yield' (state:ENTERING_SYSCALL) tid:2230725, ticks:268217806
rax:0xffffffffffffffda rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911368 global_time:3931, event:`SYSCALL: sched_yield' (state:EXITING_SYSCALL) tid:2230725, ticks:268217806
rax:0x0 rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911386 global_time:3932, event:`SYSCALL: sched_yield' (state:ENTERING_SYSCALL) tid:2230725, ticks:268217807
rax:0xffffffffffffffda rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911408 global_time:3933, event:`SYSCALL: sched_yield' (state:EXITING_SYSCALL) tid:2230725, ticks:268217807
rax:0x0 rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911426 global_time:3934, event:`SYSCALL: sched_yield' (state:ENTERING_SYSCALL) tid:2230725, ticks:268217808
rax:0xffffffffffffffda rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911439 global_time:3935, event:`SYSCALL: sched_yield' (state:EXITING_SYSCALL) tid:2230725, ticks:268217808
rax:0x0 rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911457 global_time:3936, event:`SYSCALL: sched_yield' (state:ENTERING_SYSCALL) tid:2230725, ticks:268217809
rax:0xffffffffffffffda rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911471 global_time:3937, event:`SYSCALL: sched_yield' (state:EXITING_SYSCALL) tid:2230725, ticks:268217809
rax:0x0 rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911488 global_time:3938, event:`SYSCALL: sched_yield' (state:ENTERING_SYSCALL) tid:2230725, ticks:268217810
rax:0xffffffffffffffda rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
{
real_time:149235.911501 global_time:3939, event:`SYSCALL: sched_yield' (state:EXITING_SYSCALL) tid:2230725, ticks:268217810
rax:0x0 rbx:0xefffffffffffffff rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0xffffff0000000000 rbp:0x2209c6 rsp:0x7ffd011335e8 r8:0xafffff00000fffff r9:0x4000000000000000 r10:0x792582248468 r11:0x246 r12:0x2000000000000000 r13:0x1 r14:0xfffff0000000000 r15:0x6000000000000000 rip:0x79258224f76b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x18 fs_base:0x792581c17ac0 gs_base:0x0
}
[FATAL ./src/log.cc:463:emergency_debug()] (session doesn't look interactive, aborting emergency debugging)
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackEv+0x5e)[0x5b294adece2e]
rr(_ZN2rr15notifying_abortEv+0x12)[0x5b294adece82]
rr(+0x1d8d94)[0x5b294ae03d94]
rr(+0xbf555)[0x5b294acea555]
rr(+0xc00ec)[0x5b294aceb0ec]
rr(_ZN2rr13RecordSession21process_syscall_entryEPNS_10RecordTaskEPNS0_9StepStateEPNS0_12RecordResultENS_13SupportedArchE+0x5bf)[0x5b294ad198bf]
rr(_ZN2rr13RecordSession29handle_seccomp_traced_syscallEPNS_10RecordTaskEPNS0_9StepStateEPNS0_12RecordResultEPb+0x348)[0x5b294ad11ce8]
rr(_ZN2rr13RecordSession19handle_ptrace_eventEPPNS_10RecordTaskEPNS0_9StepStateEPNS0_12RecordResultEPb+0x71a)[0x5b294ad12a5a]
rr(_ZN2rr13RecordSession11record_stepEv+0x293)[0x5b294ad1a0d3]
rr(_ZN2rr13RecordCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0xd51)[0x5b294ad0ebe1]
rr(main+0x166)[0x5b294ac791f6]
/lib/x86_64-linux-gnu/libc.so.6(+0x2a1ca)[0x7ec3a4c2a1ca]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x8b)[0x7ec3a4c2a28b]
rr(_start+0x25)[0x5b294ac7a975]
=== End rr backtrace