rr exit_test fails on ryzen 9 3900x (+ zen kernel module)

Using rr 5.5.0 from Fedora 35. Some of these failures seem to be related to the testsuite itself (e.g. it tries to break on a symbol that doesn't exist): https://gist.github.com/edwintorok/452bf733ee9f03a87cb2649813cc5188

Architecture: x86_64 CPU op-mode(s): 32-bit, 64-bit Address sizes: 43 bits physical, 48 bits virtual Byte Order: Little Endian CPU(s): 24 On-line CPU(s) list: 0-23 Vendor ID: AuthenticAMD Model name: AMD Ryzen 9 3900X 12-Core Processor CPU family: 23 Model: 113 Thread(s) per core: 2 Core(s) per socket: 12 Socket(s): 1 Stepping: 0 Frequency boost: enabled CPU max MHz: 4672.0698 CPU min MHz: 2200.0000 BogoMIPS: 7600.14 Flags: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fx sr_opt pdpe1gb rdtscp lm constant_tsc rep_good nopl nonstop_tsc cpuid extd_apicid aperfmperf rapl pni pclmulqdq monitor s sse3 fma cx16 sse4_1 sse4_2 movbe popcnt aes xsave avx f16c rdrand lahf_lm cmp_legacy svm extapic cr8_legacy abm sse4a mi salignsse 3dnowprefetch osvw ibs skinit wdt tce topoext perfctr_core perfctr_nb bpext perfctr_llc mwaitx cpb cat_l3 cdp_l 3 hw_pstate ssbd mba ibpb stibp vmmcall fsgsbase bmi1 avx2 smep bmi2 cqm rdt_a rdseed adx smap clflushopt clwb sha_ni xsa veopt xsavec xgetbv1 xsaves cqm_llc cqm_occup_llc cqm_mbm_total cqm_mbm_local clzero irperf xsaveerptr rdpru wbnoinvd ara t npt lbrv svm_lock nrip_save tsc_scale vmcb_clean flushbyasid decodeassists pausefilter pfthreshold avic v_vmsave_vmload vgif v_spec_ctrl umip rdpid overflow_recov succor smca sme sev sev_es Virtualization features: Virtualization: AMD-V Caches (sum of all):
L1d: 384 KiB (12 instances) L1i: 384 KiB (12 instances) L2: 6 MiB (12 instances) L3: 64 MiB (4 instances) NUMA:
NUMA node(s): 1 NUMA node0 CPU(s): 0-23 Vulnerabilities:
Itlb multihit: Not affected L1tf: Not affected Mds: Not affected Meltdown: Not affected Spec store bypass: Mitigation; Speculative Store Bypass disabled via prctl and seccomp Spectre v1: Mitigation; usercopy/swapgs barriers and __user pointer sanitization Spectre v2: Mitigation; Full AMD retpoline, IBPB conditional, STIBP conditional, RSB filling Srbds: Not affected Tsx async abort: Not affected

I have the kernel module for Zen installed:

dmesg|grep MSR
[  197.049667] MSR_AMD64_LS_CFG for cpu 23 was 0x6404000000000, setting to 0x46404000000000
[  197.049670] MSR_AMD64_LS_CFG for cpu 19 was 0x46404000000000, setting to 0x46404000000000
[  197.049670] MSR_AMD64_LS_CFG for cpu 7 was 0x6404000000000, setting to 0x46404000000000
[  197.049671] MSR_AMD64_LS_CFG for cpu 6 was 0x6404000000000, setting to 0x46404000000000
[  197.049672] MSR_AMD64_LS_CFG for cpu 18 was 0x46404000000000, setting to 0x46404000000000
[  197.049681] MSR_AMD64_LS_CFG for cpu 3 was 0x6404000000000, setting to 0x46404000000000
[  197.049682] MSR_AMD64_LS_CFG for cpu 15 was 0x46404000000000, setting to 0x46404000000000
[  197.049682] MSR_AMD64_LS_CFG for cpu 4 was 0x6404000000000, setting to 0x46404000000000
[  197.049683] MSR_AMD64_LS_CFG for cpu 16 was 0x46404000000000, setting to 0x46404000000000
[  197.049684] MSR_AMD64_LS_CFG for cpu 0 was 0x46404000000000, setting to 0x46404000000000
[  197.049683] MSR_AMD64_LS_CFG for cpu 12 was 0x6404000000000, setting to 0x46404000000000
[  197.049684] MSR_AMD64_LS_CFG for cpu 17 was 0x6404000000000, setting to 0x46404000000000
[  197.049685] MSR_AMD64_LS_CFG for cpu 5 was 0x46404000000000, setting to 0x46404000000000
[  197.049686] MSR_AMD64_LS_CFG for cpu 22 was 0x6404000000000, setting to 0x46404000000000
[  197.049687] MSR_AMD64_LS_CFG for cpu 10 was 0x46404000000000, setting to 0x46404000000000
[  197.049687] MSR_AMD64_LS_CFG for cpu 1 was 0x6404000000000, setting to 0x46404000000000
[  197.049688] MSR_AMD64_LS_CFG for cpu 13 was 0x46404000000000, setting to 0x46404000000000
[  197.049688] MSR_AMD64_LS_CFG for cpu 2 was 0x6404000000000, setting to 0x46404000000000
[  197.049689] MSR_AMD64_LS_CFG for cpu 14 was 0x46404000000000, setting to 0x46404000000000
[  197.049691] MSR_AMD64_LS_CFG for cpu 9 was 0x46404000000000, setting to 0x46404000000000
[  197.049690] MSR_AMD64_LS_CFG for cpu 21 was 0x6404000000000, setting to 0x46404000000000
[  197.049691] MSR_AMD64_LS_CFG for cpu 8 was 0x6404000000000, setting to 0x46404000000000
[  197.049693] MSR_AMD64_LS_CFG for cpu 20 was 0x46404000000000, setting to 0x46404000000000
[  197.049698] MSR_AMD64_LS_CFG for cpu 11 was 0x46404000000000, setting to 0x46404000000000

Is this a bug in how the rr-testsuite package was built (e.g. did it strip some symbols it shouldn't), i.e. should I open a Fedora bug too?

(I've now installed sudo dnf debuginfo-install rr-testsuite and rerunning the failed tests,will report back)

Dec 28 '21 12:12 edwintorok

Can you recheck with current master?

Dec 29 '21 12:12 GitMensch

master looks better, but there are still a few failures: https://gist.github.com/edwintorok/566efd059d1b017e2d5441ad1a3f7d97#file-master-lasttest-rerun-log (for full testsuite output run with ctest -j20 . see https://gist.github.com/edwintorok/566efd059d1b017e2d5441ad1a3f7d97) One test seems to be non-deterministic (rerunning it makes it pass), so that leaves 2 failing tests:

	944 - exit_race (Failed)
	1029 - perf_event_mmap-no-syscallbuf (Failed)

Dec 29 '21 22:12 edwintorok

perf_event_mmap-no-syscallbuf is #2975

Dec 29 '21 22:12 khuey

As there's only one left now I suggest to rename this issue to something like "exit_test fails on ryzen 9 3900x (+ zen kernel module)" and add the verbose log directly here. Also interesting: What is the output of uname -a?

Dec 29 '21 22:12 GitMensch

uname -a is: Linux fedora 5.15.11-200.fc35.x86_64 #1 SMP Wed Dec 22 15:41:11 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

The exit test also sometimes just seems to hang indefinitely (I have to ^C after several minutes and rerun it then until I get a failure).

Start testing: Dec 29 23:38 GMT
----------------------------------------------------------
944/1367 Testing: exit_race
944/1367 Test: exit_race
Command: "/usr/bin/bash" "source_dir/src/test/exit_race.run" "exit_race" "" "bin_dir" "120"
Directory: /home/edwin/rr/rr
"exit_race" start time: Dec 29 23:38 GMT
Output:
----------------------------------------------------------
source_dir/src/test/util.sh: line 245: 192814 Aborted                 (core dumped) _RR_TRACE_DIR="$workdir" test-monitor $TIMEOUT record.err $RR_EXE $GLOBAL_OPTIONS record $LIB_ARG $RECORD_ARGS "$exe" $exeargs > record.out 2> record.err
Test 'exit_race' FAILED: : error during recording:
--------------------------------------------------
[FATAL /home/edwin/rr/rr/src/RecordSession.cc:1845:process_syscall_entry()] 
 (task 192852 (rec:192852) at time 987)
 -> 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:SIGSTKFLT,errno:SUCCESS,code:sicode(1)}; IP=0x2839ac
Tail of trace dump:
{
  real_time:45469.077033 global_time:967, event:`SYSCALL: futex' (state:EXITING_SYSCALL) tid:192827, ticks:35373
rax:0x0 rbx:0x63c11915640 rcx:0xffffffffffffffff rdx:0x2f153 rsi:0x109 rdi:0x63c11915910 rbp:0x0 rsp:0x7ffcf4b05380 r8:0x0 r9:0xffffffff r10:0x0 r11:0x246 r12:0x2f153 r13:0x0 r14:0x0 r15:0x63c11915910 rip:0x28072a eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x7f6265962740 gs_base:0x0
}
{
  real_time:45469.077141 global_time:968, event:`SYSCALL: munmap' (state:ENTERING_SYSCALL) tid:192827, ticks:35397
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x1 rdi:0x4d536476b000 rbp:0x7ffcf4b05460 rsp:0x681ffdf0 r8:0x0 r9:0xffffffff r10:0x0 r11:0x246 r12:0x7ffcf4b05598 r13:0x4013cd r14:0x7f6265996c00 r15:0x403e18 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7f6265962740 gs_base:0x0
}
{
  real_time:45469.077347 global_time:969, event:`SYSCALL: munmap' (state:EXITING_SYSCALL) tid:192827, ticks:35397
rax:0x0 rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x1 rdi:0x4d536476b000 rbp:0x7ffcf4b05460 rsp:0x681ffdf0 r8:0x0 r9:0xffffffff r10:0x0 r11:0x246 r12:0x7ffcf4b05598 r13:0x4013cd r14:0x7f6265996c00 r15:0x403e18 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7f6265962740 gs_base:0x0
}
{
  real_time:45469.077465 global_time:970, event:`SYSCALL: rt_sigprocmask' (state:ENTERING_SYSCALL) tid:192827, ticks:35501
rax:0xffffffffffffffda rbx:0x7ffcf4b05448 rcx:0xffffffffffffffff rdx:0x7ffcf4b05360 rsi:0x3ad820 rdi:0x0 rbp:0x63c11915640 rsp:0x7ffcf4b052b0 r8:0xffff00 r9:0x17f22b0 r10:0x8 r11:0x246 r12:0x7ffcf4b05360 r13:0x7ffcf4b05320 r14:0x401399 r15:0x0 rip:0x284122 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe fs_base:0x7f6265962740 gs_base:0x0
}
{
  real_time:45469.077674 global_time:971, event:`SYSCALL: rt_sigprocmask' (state:EXITING_SYSCALL) tid:192827, ticks:35501
rax:0x0 rbx:0x7ffcf4b05448 rcx:0xffffffffffffffff rdx:0x7ffcf4b05360 rsi:0x3ad820 rdi:0x0 rbp:0x63c11915640 rsp:0x7ffcf4b052b0 r8:0xffff00 r9:0x17f22b0 r10:0x8 r11:0x246 r12:0x7ffcf4b05360 r13:0x7ffcf4b05320 r14:0x401399 r15:0x0 rip:0x284122 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe fs_base:0x7f6265962740 gs_base:0x0
  { tid:192827, addr:0x7ffcf4b05360, length:0x8 }
}
{
  real_time:45469.077783 global_time:972, event:`SYSCALL: clone3' (state:ENTERING_SYSCALL) tid:192827, ticks:35509
rax:0xffffffffffffffda rbx:0x7ffcf4b05220 rcx:0xffffffffffffffff rdx:0x2837f0 rsi:0x58 rdi:0x7ffcf4b05220 rbp:0xffffffffffffff80 rsp:0x7ffcf4b051d8 r8:0x63c11915640 r9:0x7ffcf4b0531f r10:0x8 r11:0x246 r12:0x63c11915640 r13:0x0 r14:0x2837f0 r15:0x0 rip:0x30862d eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x1b3 fs_base:0x7f6265962740 gs_base:0x0
}
{
  real_time:45469.077986 global_time:973, event:`SYSCALL: clone3' (state:EXITING_SYSCALL) tid:192827, ticks:35509
rax:0xffffffffffffffda rbx:0x7ffcf4b05220 rcx:0xffffffffffffffff rdx:0x2837f0 rsi:0x58 rdi:0x7ffcf4b05220 rbp:0xffffffffffffff80 rsp:0x7ffcf4b051d8 r8:0x63c11915640 r9:0x7ffcf4b0531f r10:0x8 r11:0x246 r12:0x63c11915640 r13:0x0 r14:0x2837f0 r15:0x0 rip:0x30862d eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x1b3 fs_base:0x7f6265962740 gs_base:0x0
}
{
  real_time:45469.078275 global_time:974, event:`SYSCALL: clone' (state:ENTERING_SYSCALL) tid:192827, ticks:35514
rax:0xffffffffffffffda rbx:0x7ffcf4b05220 rcx:0xffffffffffffffff rdx:0x63c11915910 rsi:0x63c11914ef0 rdi:0x3d0f00 rbp:0xffffffffffffff80 rsp:0x7ffcf4b051c8 r8:0x63c11915640 r9:0x63c11915640 r10:0x63c11915910 r11:0x246 r12:0x63c11915640 r13:0x0 r14:0x2837f0 r15:0x0 rip:0x3078c6 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x38 fs_base:0x7f6265962740 gs_base:0x0
  { map_file:"<ZERO>", addr:0x7f6265662000, length:0x200000, prot_flags:"rwxp", file_offset:0x0, device:0, inode:0, data_file:"", data_offset:0x0, file_size:0x0 }
  { tid:192827, addr:0x63c11915910, length:0x4 }
  { tid:192852, addr:0x63c11915910, length:0x4 }
  { tid:192852, addr:0x63c11915910, length:0x4 }
}
{
  real_time:45469.078469 global_time:975, event:`SYSCALL: set_robust_list' (state:ENTERING_SYSCALL) tid:192852, ticks:3
rax:0xffffffffffffffda rbx:0x63c11915640 rcx:0xffffffffffffffff rdx:0xffffffffffffff88 rsi:0x18 rdi:0x63c11915920 rbp:0x0 rsp:0x63c11914e60 r8:0x63c11915640 r9:0x63c11915640 r10:0x63c11915910 r11:0x246 r12:0x63c11915640 r13:0x0 r14:0x2837f0 r15:0x0 rip:0x2838ac eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x111 fs_base:0x63c11915640 gs_base:0x0
}
{
  real_time:45469.078673 global_time:976, event:`SYSCALL: set_robust_list' (state:EXITING_SYSCALL) tid:192852, ticks:3
rax:0x0 rbx:0x63c11915640 rcx:0xffffffffffffffff rdx:0xffffffffffffff88 rsi:0x18 rdi:0x63c11915920 rbp:0x0 rsp:0x63c11914e60 r8:0x63c11915640 r9:0x63c11915640 r10:0x63c11915910 r11:0x246 r12:0x63c11915640 r13:0x0 r14:0x2837f0 r15:0x0 rip:0x2838ac eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x111 fs_base:0x63c11915640 gs_base:0x0
}
{
  real_time:45469.078781 global_time:977, event:`SYSCALL: rt_sigprocmask' (state:ENTERING_SYSCALL) tid:192852, ticks:7
rax:0xffffffffffffffda rbx:0x63c11915640 rcx:0xffffffffffffffff rdx:0x0 rsi:0x63c11915f30 rdi:0x2 rbp:0x0 rsp:0x63c11914e60 r8:0x0 r9:0x63c11915640 r10:0x8 r11:0x246 r12:0x63c11915640 r13:0x0 r14:0x2837f0 r15:0x0 rip:0x283918 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe fs_base:0x63c11915640 gs_base:0x0
}
{
  real_time:45469.078983 global_time:978, event:`SYSCALL: rt_sigprocmask' (state:EXITING_SYSCALL) tid:192852, ticks:7
rax:0x0 rbx:0x63c11915640 rcx:0xffffffffffffffff rdx:0x0 rsi:0x63c11915f30 rdi:0x2 rbp:0x0 rsp:0x63c11914e60 r8:0x0 r9:0x63c11915640 r10:0x8 r11:0x246 r12:0x63c11915640 r13:0x0 r14:0x2837f0 r15:0x0 rip:0x283918 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xe fs_base:0x63c11915640 gs_base:0x0
}
{
  real_time:45469.079090 global_time:979, event:`SYSCALL: gettid' (state:ENTERING_SYSCALL) tid:192852, ticks:12
rax:0xffffffffffffffda rbx:0x7f6265861fa0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x0 rbp:0x63c11914e50 rsp:0x7f6265861df0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x63c11915640 r13:0x0 r14:0x2837f0 r15:0x0 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xba fs_base:0x63c11915640 gs_base:0x0
}
{
  real_time:45469.079292 global_time:980, event:`SYSCALL: gettid' (state:EXITING_SYSCALL) tid:192852, ticks:12
rax:0x2f154 rbx:0x7f6265861fa0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x0 rbp:0x63c11914e50 rsp:0x7f6265861df0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x63c11915640 r13:0x0 r14:0x2837f0 r15:0x0 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xba fs_base:0x63c11915640 gs_base:0x0
}
{
  real_time:45469.079396 global_time:981, event:`SYSCALL: perf_event_open' (state:ENTERING_SYSCALL) tid:192852, ticks:12
rax:0xffffffffffffffda rbx:0x7f6265861fa0 rcx:0xffffffffffffffff rdx:0xffffffffffffffff rsi:0x0 rdi:0x7f6265861e60 rbp:0x7f6265861e60 rsp:0x7f6265861df0 r8:0x0 r9:0x0 r10:0xffffffffffffffff r11:0x246 r12:0x63c11915640 r13:0x2f154 r14:0x2837f0 r15:0x0 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x12a fs_base:0x63c11915640 gs_base:0x0
}
{
  real_time:45469.079605 global_time:982, event:`SYSCALL: perf_event_open' (state:EXITING_SYSCALL) tid:192852, ticks:12
rax:0x4 rbx:0x7f6265861fa0 rcx:0xffffffffffffffff rdx:0xffffffffffffffff rsi:0x0 rdi:0x7f6265861e60 rbp:0x7f6265861e60 rsp:0x7f6265861df0 r8:0x0 r9:0x0 r10:0xffffffffffffffff r11:0x246 r12:0x63c11915640 r13:0x2f154 r14:0x2837f0 r15:0x0 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x12a fs_base:0x63c11915640 gs_base:0x0
}
{
  real_time:45469.079708 global_time:983, event:`SYSCALL: fcntl' (state:ENTERING_SYSCALL) tid:192852, ticks:13
rax:0xffffffffffffffda rbx:0x7f6265861fa0 rcx:0xffffffffffffffff rdx:0x64 rsi:0x406 rdi:0x4 rbp:0x7f6265861e60 rsp:0x7f6265861d90 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x4 r13:0x2f154 r14:0x2837f0 r15:0x0 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x48 fs_base:0x63c11915640 gs_base:0x0
}
{
  real_time:45469.079922 global_time:984, event:`SYSCALL: fcntl' (state:EXITING_SYSCALL) tid:192852, ticks:13
rax:0x65 rbx:0x7f6265861fa0 rcx:0xffffffffffffffff rdx:0x64 rsi:0x406 rdi:0x4 rbp:0x7f6265861e60 rsp:0x7f6265861d90 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x4 r13:0x2f154 r14:0x2837f0 r15:0x0 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x48 fs_base:0x63c11915640 gs_base:0x0
  { tid:192827, addr:0x54295defb2ad, length:0x1 }
}
{
  real_time:45469.080027 global_time:985, event:`SYSCALL: rrcall_init_buffers' (state:ENTERING_SYSCALL) tid:192852, ticks:18
rax:0xffffffffffffffda rbx:0x7f6265861fa0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x7f6265861e60 rbp:0x7f6265861e60 rsp:0x7f6265861df0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x4 r13:0x2f154 r14:0x65 r15:0x0 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x3e9 fs_base:0x63c11915640 gs_base:0x0
}
{
  real_time:45469.080448 global_time:986, event:`SYSCALL: rrcall_init_buffers' (state:EXITING_SYSCALL) tid:192852, ticks:18
rax:0x7f6265562000 rbx:0x7f6265861fa0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x7f6265861e60 rbp:0x7f6265861e60 rsp:0x7f6265861df0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x4 r13:0x2f154 r14:0x65 r15:0x0 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x3e9 fs_base:0x63c11915640 gs_base:0x0
  { map_file:"<ZERO>", addr:0x7f6265562000, length:0x100000, prot_flags:"rw-s", file_offset:0x0, device:40, inode:419269, data_file:"", data_offset:0x0, file_size:0x100000 }
  { tid:192827, addr:0x54295defb2ad, length:0x1 }
  { tid:192852, addr:0x7f6265861e60, length:0x20 }
}
process 192815 sent SIGURG
====== /proc/192815/status
Name:	rr
Umask:	0022
State:	S (sleeping)
Tgid:	192815
Ngid:	0
Pid:	192815
PPid:	192814
TracerPid:	0
Uid:	1000	1000	1000	1000
Gid:	1000	1000	1000	1000
FDSize:	64
Groups:	10 1000 
NStgid:	192815
NSpid:	192815
NSpgid:	192815
NSsid:	86074
VmPeak:	 1003768 kB
VmSize:	  784816 kB
VmLck:	       0 kB
VmPin:	       0 kB
VmHWM:	   33872 kB
VmRSS:	   27488 kB
RssAnon:	   18528 kB
RssFile:	    8948 kB
RssShmem:	      12 kB
VmData:	   62148 kB
VmStk:	     132 kB
VmExe:	    2760 kB
VmLib:	    3736 kB
VmPTE:	     180 kB
VmSwap:	       0 kB
HugetlbPages:	       0 kB
CoreDumping:	0
THP_enabled:	1
Threads:	1
SigQ:	0/256624
SigPnd:	0000000000000000
ShdPnd:	0000000000000000
SigBlk:	0000000000000000
SigIgn:	0000000000000025
SigCgt:	0000000100006400
CapInh:	0000000000000000
CapPrm:	0000000000000000
CapEff:	0000000000000000
CapBnd:	000001ffffffffff
CapAmb:	0000000000000000
NoNewPrivs:	0
Seccomp:	0
Seccomp_filters:	0
Speculation_Store_Bypass:	thread vulnerable
SpeculationIndirectBranch:	conditional enabled
Cpus_allowed:	00200000
Cpus_allowed_list:	21
Mems_allowed:	00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000001
Mems_allowed_list:	0
voluntary_ctxt_switches:	1684
nonvoluntary_ctxt_switches:	209
====== /proc/192815/stack
====== /proc/192827/status
Name:	exit_race-VRTnL
Umask:	0022
State:	t (tracing stop)
Tgid:	192827
Ngid:	0
Pid:	192827
PPid:	192815
TracerPid:	192815
Uid:	1000	1000	1000	1000
Gid:	1000	1000	1000	1000
FDSize:	1024
Groups:	10 1000 
NStgid:	192827
NSpid:	192827
NSpgid:	192815
NSsid:	86074
VmPeak:	   25256 kB
VmSize:	   25252 kB
VmLck:	       0 kB
VmPin:	       0 kB
VmHWM:	    1740 kB
VmRSS:	    1732 kB
RssAnon:	     292 kB
RssFile:	    1420 kB
RssShmem:	      20 kB
VmData:	   20876 kB
VmStk:	       0 kB
VmExe:	       4 kB
VmLib:	    1704 kB
VmPTE:	     104 kB
VmSwap:	       0 kB
HugetlbPages:	       0 kB
CoreDumping:	0
THP_enabled:	1
Threads:	2
SigQ:	0/256624
SigPnd:	0000000000000000
ShdPnd:	0000000000000000
SigBlk:	ffffffffdffb7eff
SigIgn:	0000000000000000
SigCgt:	0000000100000000
CapInh:	0000000000000000
CapPrm:	0000000000000000
CapEff:	0000000000000000
CapBnd:	000001ffffffffff
CapAmb:	0000000000000000
NoNewPrivs:	1
Seccomp:	2
Seccomp_filters:	1
Speculation_Store_Bypass:	thread force mitigated
SpeculationIndirectBranch:	conditional force disabled
Cpus_allowed:	00200000
Cpus_allowed_list:	21
Mems_allowed:	00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000001
Mems_allowed_list:	0
voluntary_ctxt_switches:	532
nonvoluntary_ctxt_switches:	0
====== /proc/192827/stack
====== /proc/192852/status
Name:	exit_race-VRTnL
Umask:	0022
State:	t (tracing stop)
Tgid:	192827
Ngid:	0
Pid:	192852
PPid:	192815
TracerPid:	192815
Uid:	1000	1000	1000	1000
Gid:	1000	1000	1000	1000
FDSize:	1024
Groups:	10 1000 
NStgid:	192827
NSpid:	192852
NSpgid:	192815
NSsid:	86074
VmPeak:	   25256 kB
VmSize:	   25252 kB
VmLck:	       0 kB
VmPin:	       0 kB
VmHWM:	    1740 kB
VmRSS:	    1732 kB
RssAnon:	     292 kB
RssFile:	    1420 kB
RssShmem:	      20 kB
VmData:	   20876 kB
VmStk:	       0 kB
VmExe:	       4 kB
VmLib:	    1704 kB
VmPTE:	     104 kB
VmSwap:	       0 kB
HugetlbPages:	       0 kB
CoreDumping:	0
THP_enabled:	1
Threads:	2
SigQ:	0/256624
SigPnd:	0000000000000000
ShdPnd:	0000000000000000
SigBlk:	0000000000000000
SigIgn:	0000000000000000
SigCgt:	0000000100000000
CapInh:	0000000000000000
CapPrm:	0000000000000000
CapEff:	0000000000000000
CapBnd:	000001ffffffffff
CapAmb:	0000000000000000
NoNewPrivs:	1
Seccomp:	2
Seccomp_filters:	1
Speculation_Store_Bypass:	thread force mitigated
SpeculationIndirectBranch:	conditional force disabled
Cpus_allowed:	00200000
Cpus_allowed_list:	21
Mems_allowed:	00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000001
Mems_allowed_list:	0
voluntary_ctxt_switches:	23
nonvoluntary_ctxt_switches:	0
====== /proc/192852/stack
====== gdb -p 192815 -ex 'set confirm off' -ex 'set height 0' -ex 'thread apply all bt' -ex q </dev/null 2>&1
GNU gdb (GDB) Fedora 11.1-5.fc35
Copyright (C) 2021 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word".
Attaching to process 192815
Reading symbols from /home/edwin/rr/rr/bin/rr...
Reading symbols from /lib64/libcapnp.so.0.8.0...
Reading symbols from /home/edwin/.cache/debuginfod_client/3ce07e330266b8f0d3d653db7d2e5a90a57cc0e8/debuginfo...
Reading symbols from /lib64/libkj.so.0.8.0...
Reading symbols from /home/edwin/.cache/debuginfod_client/81454fbc812588953d1c1beb74c0ae8d8c949999/debuginfo...
Reading symbols from /lib64/libstdc++.so.6...
Reading symbols from /home/edwin/.cache/debuginfod_client/64dc8524cb0109c7f3d3c0ef3d4d6ec9979db75c/debuginfo...
Reading symbols from /lib64/libm.so.6...
Reading symbols from /home/edwin/.cache/debuginfod_client/cea55efc551e62cd8439d044aa9a765c445fb7bf/debuginfo...
Reading symbols from /lib64/libgcc_s.so.1...
Reading symbols from /home/edwin/.cache/debuginfod_client/88564abce789aa42536da1247a57ff6062d61dcb/debuginfo...
Reading symbols from /lib64/libc.so.6...
Reading symbols from /home/edwin/.cache/debuginfod_client/644dac2c66a6e0b32674f0ec71e7431bd0c06a63/debuginfo...
Reading symbols from /lib64/ld-linux-x86-64.so.2...
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
0x00007f1aa8672e0f in __libc_accept (fd=4, addr=..., len=0x0) at ../sysdeps/unix/sysv/linux/accept.c:26
26	  return SYSCALL_CANCEL (accept, fd, addr.__sockaddr__, len);

Thread 1 (Thread 0x7f1aa855b740 (LWP 192815) "rr"):
#0  0x00007f1aa8672e0f in __libc_accept (fd=4, addr=..., len=0x0) at ../sysdeps/unix/sysv/linux/accept.c:26
#1  0x0000000000769722 in rr::GdbConnection::await_debugger (this=0x115b350, listen_fd=...) at /home/edwin/rr/rr/src/GdbConnection.cc:71
#2  0x00000000007852f0 in rr::await_connection (t=0x1160140, listen_fd=..., features=...) at /home/edwin/rr/rr/src/GdbServer.cc:1690
#3  0x0000000000786709 in rr::GdbServer::emergency_debug (t=0x1160140) at /home/edwin/rr/rr/src/GdbServer.cc:1893
#4  0x00000000007b86c3 in rr::emergency_debug (t=0x1160140) at /home/edwin/rr/rr/src/log.cc:408
#5  0x00000000007b88aa in rr::EmergencyDebugOstream::~EmergencyDebugOstream (this=0x7fff19a81800, __in_chrg=<optimized out>) at /home/edwin/rr/rr/src/log.cc:430
#6  0x00000000007fa46c in rr::RecordSession::process_syscall_entry (this=0x1153760, t=0x1160140, step_state=0x7fff19a8235c, step_result=0x7fff19a82420, syscall_arch=rr::x86_64) at /home/edwin/rr/rr/src/RecordSession.cc:1845
#7  0x00000000007f48b6 in rr::RecordSession::handle_seccomp_traced_syscall (this=0x1153760, t=0x1160140, step_state=0x7fff19a8235c, result=0x7fff19a82420, did_enter_syscall=0x7fff19a8235b) at /home/edwin/rr/rr/src/RecordSession.cc:420
#8  0x00000000007f554a in rr::RecordSession::handle_ptrace_event (this=0x1153760, t_ptr=0x7fff19a82360, step_state=0x7fff19a8235c, result=0x7fff19a82420, did_enter_syscall=0x7fff19a8235b) at /home/edwin/rr/rr/src/RecordSession.cc:643
#9  0x00000000007fd136 in rr::RecordSession::record_step (this=0x1153760) at /home/edwin/rr/rr/src/RecordSession.cc:2390
#10 0x00000000007f07c7 in rr::record (args=std::vector of length 1, capacity 8 = {...}, flags=...) at /home/edwin/rr/rr/src/RecordCommand.cc:662
#11 0x00000000007f132b in rr::RecordCommand::run (this=0xb4bf00 <rr::RecordCommand::singleton>, args=std::vector of length 1, capacity 8 = {...}) at /home/edwin/rr/rr/src/RecordCommand.cc:812
#12 0x000000000095cc42 in main (argc=9, argv=0x7fff19a827c8) at /home/edwin/rr/rr/src/main.cc:268
Detaching from program: /home/edwin/rr/rr/bin/rr, process 192815
[Inferior 1 (process 192815) detached]
warning: Could not load shared library symbols for linux-vdso.so.1.
Do you need "set solib-search-path" or "set sysroot"?
[FATAL /home/edwin/rr/rr/src/log.cc:409:emergency_debug()] Can't resume execution from invalid state
t_race-VRTnLuobM
 </dev/null 2>&1
GNU gdb (GDB) Fedora 11.1-5.fc35
Copyright (C) 2021 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /tmp/rr-test-exit_race-VRTnLuobM/exit_race-VRTnLuobM...
Remote debugging using 127.0.0.1:61780
Reading symbols from /home/edwin/rr/rr/lib/rr/librrpreload.so...
Reading symbols from /lib64/libc.so.6...
Reading symbols from /home/edwin/.cache/debuginfod_client/644dac2c66a6e0b32674f0ec71e7431bd0c06a63/debuginfo...
Reading symbols from /lib64/ld-linux-x86-64.so.2...
start_thread (arg=<optimized out>) at pthread_create.c:506
506	  __libc_lock_lock (pd->exit_lock);
--------------------------------------------------
record.out:
--------------------------------------------------
--------------------------------------------------
Test exit_race failed, leaving behind /tmp/rr-test-exit_race-VRTnLuobM
To replay the failed test, run
  _RR_TRACE_DIR=/tmp/rr-test-exit_race-VRTnLuobM rr replay
<end of output>
Test time =   1.97 sec
----------------------------------------------------------
Test Fail Reason:
Error regular expression found in output. Regex=[FAILED]
"exit_race" end time: Dec 29 23:38 GMT
"exit_race" time elapsed: 00:00:01
----------------------------------------------------------

Dec 29 '21 23:12 edwintorok

rr rr copied to clipboard

exit_test fails on ryzen 9 3900x (+ zen kernel module)

rr
rr copied to clipboard