rr-debugger / rr

Record and Replay Framework
http://rr-project.org/
Other
9.18k stars 585 forks source link

Error when recording: "The futex facility returned an unexpected error code." #3358

Open russkel opened 2 years ago

russkel commented 2 years ago

I am running the debian binaries and master branch on my Ubuntu 22.04 x86_64 machine. I am getting this error upon upgrading to 5.6.0. I downgraded to 5.5.0 and it seems to be working.

According to the last comment in this issue it's to do with a mismatch between some libraries or glibc versions: https://github.com/rr-debugger/rr/issues/2767

With version 5.6.0:

↳ rr record integration-service config.yaml
rr: Saving execution to trace directory `/home/russ/.local/share/rr/integration-service-4'.
[Integration Service][INFO] [is::sh::ROS2] Created node '/is_ros2_node_1804289383' with Domain ID: 0
The futex facility returned an unexpected error code.
zsh: IOT instruction  rr record integration-service config.yaml

With version 5.5.0 (segfault is in my code):

↳ rr record integration-service config.yaml
rr: Saving execution to trace directory `/home/russ/.local/share/rr/integration-service-5'.
[Integration Service][INFO] [is::sh::ROS2] Created node '/is_ros2_node_1804289383' with Domain ID: 0
[Integration Service][INFO] [is::sh::ROS2] Configured!
zsh: segmentation fault  rr record integration-service config.yaml
Keno commented 2 years ago

Can you try building from source?

russkel commented 2 years ago

@Keno I have compiled from source and it is recording correctly. Maybe there is a need for a separate build for jammy and focal?

EDIT: This is no longer the case. Running from source errors.

rocallahan commented 2 years ago

In the past binaries built with Ubuntu 18 have worked on later Ubuntus.

Can you get a stack trace of the point where "The futex facility returned an unexpected error code" is printed?

russkel commented 2 years ago

I certainly can. Do you have a command I could run to generate that?

rocallahan commented 2 years ago

rr replay -a -M on the recording with the futex failure, then get the event number of the message --- the last value of the triple [rr <pid> <event>], then rr replay -g <event>.

khuey commented 2 years ago

This could be related to the DOUBLE_UNDERSCORE_PTHREAD_LOCK_AVAILABLE stuff. jammy has glibc 2.35

russkel commented 2 years ago

rr replay -a -M on the recording with the futex failure, then get the event number of the message --- the last value of the triple [rr <pid> <event>], then rr replay -g <event>.

Thanks for that.

gef➤  bt
#0  writev_for_fatal (total=<optimised out>, niov=<optimised out>, iov=<optimised out>, fd=<optimised out>) at ../sysdeps/unix/sysv/linux/libc_fatal.c:31
#1  __libc_message (action=do_abort, fmt=0x7fcbeb9ee7b1 "%s", fmt=0x7fcbeb9ee7b1 "%s", action=do_abort) at ../sysdeps/posix/libc_fatal.c:124
#2  0x00007fcbeb89c770 in __GI___libc_fatal (message=<optimised out>) at ../sysdeps/posix/libc_fatal.c:164
#3  0x00007fcbeb8a412e in futex_fatal_error () at ../sysdeps/nptl/futex-internal.h:87
#4  __futex_abstimed_wait_common (cancel=0x1, private=<optimised out>, abstime=0x0, clockid=0x0, expected=0x0, futex_word=0x7fcbeb5cf9a8) at ./nptl/futex-internal.c:119
#5  __GI___futex_abstimed_wait_cancelable64 (futex_word=futex_word@entry=0x7fcbeb5cf9a8, expected=expected@entry=0x0, clockid=clockid@entry=0x0, abstime=abstime@entry=0x0, private=<optimised out>) at ./nptl/futex-internal.c:139
#6  0x00007fcbeb8afc5f in do_futex_wait (sem=sem@entry=0x7fcbeb5cf9a8, abstime=0x0, clockid=0x0) at ./nptl/sem_waitcommon.c:111
#7  0x00007fcbeb8afcf8 in __new_sem_wait_slow64 (sem=0x7fcbeb5cf9a8, abstime=0x0, clockid=0x0) at ./nptl/sem_waitcommon.c:183
#8  0x00007fcbeb53e912 in rclcpp::SignalHandler::wait_for_signal() () from /opt/ros/humble/lib/librclcpp.so
#9  0x00007fcbeb53f97e in rclcpp::SignalHandler::deferred_signal_handler() () from /opt/ros/humble/lib/librclcpp.so
#10 0x00007fcbebb172c3 in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
#11 0x00007fcbeb8a7b43 in start_thread (arg=<optimised out>) at ./nptl/pthread_create.c:442
#12 0x00007fcbeb938bb4 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100
khuey commented 2 years ago

Try doing rr replay -g <event - 1>.

khuey commented 2 years ago

That stack is just a little too far.

russkel commented 2 years ago

No problem:

gef➤  bt
#0  __futex_abstimed_wait_common64 (private=<optimised out>, cancel=0x1, abstime=0x0, op=0x189, expected=0x0, futex_word=0x7fcbeb5cf9a8) at ./nptl/futex-internal.c:57
#1  __futex_abstimed_wait_common (cancel=0x1, private=<optimised out>, abstime=0x0, clockid=0x0, expected=0x0, futex_word=0x7fcbeb5cf9a8) at ./nptl/futex-internal.c:87
#2  __GI___futex_abstimed_wait_cancelable64 (futex_word=futex_word@entry=0x7fcbeb5cf9a8, expected=expected@entry=0x0, clockid=clockid@entry=0x0, abstime=abstime@entry=0x0, private=<optimised out>) at ./nptl/futex-internal.c:139
#3  0x00007fcbeb8afc5f in do_futex_wait (sem=sem@entry=0x7fcbeb5cf9a8, abstime=0x0, clockid=0x0) at ./nptl/sem_waitcommon.c:111
#4  0x00007fcbeb8afcf8 in __new_sem_wait_slow64 (sem=0x7fcbeb5cf9a8, abstime=0x0, clockid=0x0) at ./nptl/sem_waitcommon.c:183
#5  0x00007fcbeb53e912 in rclcpp::SignalHandler::wait_for_signal() () from /opt/ros/humble/lib/librclcpp.so
#6  0x00007fcbeb53f97e in rclcpp::SignalHandler::deferred_signal_handler() () from /opt/ros/humble/lib/librclcpp.so
#7  0x00007fcbebb172c3 in ?? () from /lib/x86_64-linux-gnu/libstdc++.so.6
#8  0x00007fcbeb8a7b43 in start_thread (arg=<optimised out>) at ./nptl/pthread_create.c:442
#9  0x00007fcbeb938bb4 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100
khuey commented 2 years ago

info reg please

russkel commented 2 years ago

info reg please

gef➤  info reg
rax            0xfffffffffffffe00  0xfffffffffffffe00
rbx            0x7fcbeb5cf9a8      0x7fcbeb5cf9a8
rcx            0xffffffffffffffff  0xffffffffffffffff
rdx            0x0                 0x0
rsi            0x189               0x189
rdi            0x7fcbeb5cf9a8      0x7fcbeb5cf9a8
rbp            0x0                 0x0
rsp            0x7fcbea4b7500      0x7fcbea4b7500
r8             0x0                 0x0
r9             0xffffffff          0xffffffff
r10            0x0                 0x0
r11            0x246               0x246
r12            0x0                 0x0
r13            0x0                 0x0
r14            0x7fcbeb8a7850      0x7fcbeb8a7850
r15            0x7fffb97999d0      0x7fffb97999d0
rip            0x7fcbeb8a4197      0x7fcbeb8a4197 <__GI___futex_abstimed_wait_cancelable64+231>
eflags         0x246               [ PF ZF IF ]
cs             0x33                0x33
ss             0x2b                0x2b
ds             0x0                 0x0
es             0x0                 0x0
fs             0x0                 0x0
gs             0x0                 0x0
khuey commented 2 years ago

Hmm, if you stepi does rax change (i.e. p/x $rax afterwards)?

khuey commented 2 years ago

That value is -ERESTARTSYS, I guess we're letting it leak out somehow.

russkel commented 2 years ago

Yeah looks like it does:

gef➤  p/x $rax
$1 = 0xca
khuey commented 2 years ago

I struggle to see why the handling of this would vary depending on what machine it was built on though.

Keno commented 2 years ago

ERESTARTSYS leaking was supposed to have been fixed by https://github.com/rr-debugger/rr/pull/3148/commits/21e00d1e31dcdd32df31f0ddf16fc0f3e9beba00

russkel commented 2 years ago

I may have been incorrect. I have compiled the master branch and installed it, and I am getting the same error still. I am not sure why the error disappeared during the above testing a few weeks ago. I am thinking the deb binary is a red herring.

GitMensch commented 2 years ago

I may have been incorrect. I have compiled the master branch and installed it, and I am getting the same error still. I am not sure why the error disappeared during the above testing a few weeks ago. I am thinking the deb binary is a red herring.

Would you mind to re-verify and if this is "just" 5.6.0 bit working on Ubuntu 22.04 then please adjust the issue title and as it is missing here: did your build from master pass all the included tests?

russkel commented 2 years ago

Sure. I believe I had conflicting installs of rr installed because using install instructions caused the sudo make install. I have cleaned up the version and made sure there was nothing in either /usr/{bin,lib} or /usr/local/.

I have removed the installed version[s], pulled master, cleaned and built and ran the tests and I am getting failed tests on master AND failed execution as above:

$ russ @ kalesmoothie in ~/work/is-workspace [14:35:31]
↳ ~/work/rr/obj/bin/rr --version
rr version 5.6.0

$ russ @ kalesmoothie in ~/work/is-workspace [14:45:57]
↳ ~/work/rr/obj/bin/rr record integration-service CAN-SH/CAN-SH/config.yaml
rr: Saving execution to trace directory `/home/russ/.local/share/rr/integration-service-16'.
[Integration Service][INFO] [is::sh::ROS2] Created node '/is_ros2_node_1804289383' with Domain ID: 0
The futex facility returned an unexpected error code.
zsh: IOT instruction  ~/work/rr/obj/bin/rr record integration-service CAN-SH/CAN-SH/config.yaml

Test failures:

99% tests passed, 4 tests failed out of 2841

Total Test time (real) = 2452.12 sec

The following tests FAILED:
    460 - x86/pkeys (Failed)
    461 - x86/pkeys-no-syscallbuf (Failed)
    1880 - x86/pkeys-32 (Failed)
    1881 - x86/pkeys-32-no-syscallbuf (Failed)
Errors while running CTest
460/2841 Testing: x86/pkeys
460/2841 Test: x86/pkeys
Command: "/usr/bin/bash" "source_dir/src/test/basic_test.run" "pkeys" "" "bin_dir" "120"
Directory: /home/russ/work/rr/obj
"x86/pkeys" start time: Sep 26 13:28 CEST
Output:
----------------------------------------------------------
source_dir/src/test/util.sh: line 287: 4147453 Aborted                 (core dumped) _RR_TRACE_DIR="$workdir" test-monitor $TIMEOUT replay.err $RR_EXE $GLOBAL_OPTIONS replay -a $replayflags > replay.out 2> replay.err
Test 'pkeys' FAILED: : error during replay:
--------------------------------------------------
[FATAL src/ReplaySession.cc:1173:check_ticks_consistency()] 
 (task 4147455 (rec:4147452) at time 191)
 -> Assertion `ticks_now == trace_ticks' failed to hold. ticks mismatch for 'PATCH_SYSCALL'; expected 33295, got 33651
Tail of trace dump:
{
  real_time:273919.899730 global_time:171, event:`SYSCALL: mprotect' (state:EXITING_SYSCALL) tid:4147452, ticks:31831
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x2000 rdi:0x7f95a596d000 rbp:0x7ffdec90c3b0 rsp:0x7ffdec90c2a8 r8:0x7f95a56d5e60 r9:0x0 r10:0x7f95a5935000 r11:0x246 r12:0x0 r13:0x0 r14:0x7f95a596faf0 r15:0x7f95a596faf0 rip:0x7f95a595bd4b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xa fs_base:0x7f95a56cb740 gs_base:0x0
}
{
  real_time:273919.899798 global_time:172, event:`INSTRUCTION_TRAP' tid:4147452, ticks:31833
rax:0xb7069065 rbx:0x23e03b6fc8417 rcx:0xffffffffffffffff rdx:0x23e03 rsi:0x2000 rdi:0x7f95a596d000 rbp:0x7ffdec90c690 rsp:0x7ffdec90c3c0 r8:0x7f95a56d5e60 r9:0x0 r10:0x7f95a5935000 r11:0x246 r12:0x7f95a59702e0 r13:0xfffffffffffffff8 r14:0x7f95a56cb740 r15:0x7f95a59702e0 rip:0x7f95a5959232 eflags:0x10246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f95a56cb740 gs_base:0x0
}
{
  real_time:273919.899862 global_time:173, event:`SYSCALL: prlimit64' (state:ENTERING_SYSCALL) tid:4147452, ticks:31856
rax:0xffffffffffffffda rbx:0x1 rcx:0xffffffffffffffff rdx:0x0 rsi:0x3 rdi:0x0 rbp:0x7ffdec90c690 rsp:0x7ffdec90c388 r8:0x0 r9:0xf r10:0x7ffdec90c390 r11:0x246 r12:0x7f95a59702e0 r13:0xfffffffffffffff8 r14:0x7f95a56cb740 r15:0x7f95a59702e0 rip:0x7f95a57e8494 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x12e fs_base:0x7f95a56cb740 gs_base:0x0
}
{
  real_time:273919.899984 global_time:174, event:`SYSCALL: prlimit64' (state:EXITING_SYSCALL) tid:4147452, ticks:31856
rax:0x0 rbx:0x1 rcx:0xffffffffffffffff rdx:0x0 rsi:0x3 rdi:0x0 rbp:0x7ffdec90c690 rsp:0x7ffdec90c388 r8:0x0 r9:0xf r10:0x7ffdec90c390 r11:0x246 r12:0x7f95a59702e0 r13:0xfffffffffffffff8 r14:0x7f95a56cb740 r15:0x7f95a59702e0 rip:0x7f95a57e8494 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x12e fs_base:0x7f95a56cb740 gs_base:0x0
  { tid:4147452, addr:0x7ffdec90c390, length:0x10 }
}
{
  real_time:273919.900062 global_time:175, event:`SYSCALL: munmap' (state:ENTERING_SYSCALL) tid:4147452, ticks:31991
rax:0xffffffffffffffda rbx:0x7f95a5970118 rcx:0xffffffffffffffff rdx:0x7f95a575ec90 rsi:0x2a51b rdi:0x7f95a58f6000 rbp:0x7ffdec90c690 rsp:0x7ffdec90c3a8 r8:0x0 r9:0xf r10:0x7f95a5935860 r11:0x246 r12:0x7f95a59702e0 r13:0xfffffffffffffff8 r14:0x7f95a56cb740 r15:0x7f95a59702e0 rip:0x7f95a595bd1b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7f95a56cb740 gs_base:0x0
}
{
  real_time:273919.900188 global_time:176, event:`SYSCALL: munmap' (state:EXITING_SYSCALL) tid:4147452, ticks:31991
rax:0x0 rbx:0x7f95a5970118 rcx:0xffffffffffffffff rdx:0x7f95a575ec90 rsi:0x2a51b rdi:0x7f95a58f6000 rbp:0x7ffdec90c690 rsp:0x7ffdec90c3a8 r8:0x0 r9:0xf r10:0x7f95a5935860 r11:0x246 r12:0x7f95a59702e0 r13:0xfffffffffffffff8 r14:0x7f95a56cb740 r15:0x7f95a59702e0 rip:0x7f95a595bd1b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7f95a56cb740 gs_base:0x0
}
{
  real_time:273919.900275 global_time:177, event:`SYSCALL: rrcall_init_preload' (state:ENTERING_SYSCALL) tid:4147452, ticks:32403
rax:0xffffffffffffffda rbx:0x7ffdec90c3c0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x7ffdec90c360 rbp:0x1 rsp:0x7ffdec90c348 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x7ffdec90c808 r13:0x7ffdec90c818 r14:0x7f95a592be50 r15:0x0 rip:0x7f95a57eca3d eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x3e8 fs_base:0x7f95a56cb740 gs_base:0x0
}
{
  real_time:273919.900413 global_time:178, event:`SYSCALL: rrcall_init_preload' (state:EXITING_SYSCALL) tid:4147452, ticks:32403
rax:0x0 rbx:0x7ffdec90c3c0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x7ffdec90c360 rbp:0x1 rsp:0x7ffdec90c348 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x7ffdec90c808 r13:0x7ffdec90c818 r14:0x7f95a592be50 r15:0x0 rip:0x7f95a57eca3d eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x3e8 fs_base:0x7f95a56cb740 gs_base:0x0
  { tid:4147452, addr:0x7f95a592c428, length:0x400 }
  { tid:4147452, addr:0x7f95a592c422, length:0x1 }
  { tid:4147452, addr:0x7f95a592c423, length:0x1 }
  { tid:4147452, addr:0x7f95a59325e8, length:0x8 }
}
{
  real_time:273919.900493 global_time:179, event:`INSTRUCTION_TRAP' tid:4147452, ticks:33265
rax:0x2 rbx:0xf3bba7eb rcx:0x18c05fde rdx:0xfc100510 rsi:0x0 rdi:0x7 rbp:0x7ffdec90c6b0 rsp:0x7ffdec90c6a8 r8:0x7ffdec90c6d4 r9:0x7f95a593b040 r10:0x7f95a5935908 r11:0x7f95a5950680 r12:0x7ffdec90c808 r13:0x56474160850d r14:0x56474160ad78 r15:0x7f95a596f040 rip:0x56474160846a eflags:0x10246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f95a56cb740 gs_base:0x0
}
{
  real_time:273919.900618 global_time:180, event:`PATCH_SYSCALL' tid:4147452, ticks:33267
rax:0x14a rbx:0x0 rcx:0xffffffffffffffff rdx:0x35 rsi:0x0 rdi:0x0 rbp:0x7ffdec90c6f0 rsp:0x7ffdec90c6b8 r8:0x7f95a593b040 r9:0x0 r10:0x7ffdec90c6d4 r11:0x246 r12:0x7ffdec90c808 r13:0x56474160850d r14:0x56474160ad78 r15:0x7f95a596f040 rip:0x7f95a57eca3b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f95a56cb740 gs_base:0x0
  { map_file:"<ZERO>", addr:0x7f95a58f7000, length:0x1000, prot_flags:"r-xp", file_offset:0x0, device:0, inode:0, data_file:"", data_offset:0x0, file_size:0x1000 }
  { tid:4147452, addr:0x7f95a58f7000, length:0x5e }
  { tid:4147452, addr:0x7f95a57eca3b, length:0x8 }
}
{
  real_time:273919.900680 global_time:181, event:`SYSCALL: gettid' (state:ENTERING_SYSCALL) tid:4147452, ticks:33271
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x0 rbp:0x681fffa0 rsp:0x681ffdd0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x7ffdec90c808 r13:0x56474160850d r14:0x56474160ad78 r15:0x7f95a596f040 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xba fs_base:0x7f95a56cb740 gs_base:0x0
}
{
  real_time:273919.900798 global_time:182, event:`SYSCALL: gettid' (state:EXITING_SYSCALL) tid:4147452, ticks:33271
rax:0x3f48fc rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x0 rbp:0x681fffa0 rsp:0x681ffdd0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x7ffdec90c808 r13:0x56474160850d r14:0x56474160ad78 r15:0x7f95a596f040 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xba fs_base:0x7f95a56cb740 gs_base:0x0
}
{
  real_time:273919.900866 global_time:183, event:`SYSCALL: perf_event_open' (state:ENTERING_SYSCALL) tid:4147452, ticks:33271
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0xffffffffffffffff rsi:0x0 rdi:0x681ffe50 rbp:0x681fffa0 rsp:0x681ffdd0 r8:0x0 r9:0x0 r10:0xffffffffffffffff r11:0x246 r12:0x7ffdec90c808 r13:0x681ffe50 r14:0x3f48fc r15:0x7f95a596f040 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x12a fs_base:0x7f95a56cb740 gs_base:0x0
}
{
  real_time:273919.901105 global_time:184, event:`SYSCALL: perf_event_open' (state:EXITING_SYSCALL) tid:4147452, ticks:33271
rax:0x4 rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0xffffffffffffffff rsi:0x0 rdi:0x681ffe50 rbp:0x681fffa0 rsp:0x681ffdd0 r8:0x0 r9:0x0 r10:0xffffffffffffffff r11:0x246 r12:0x7ffdec90c808 r13:0x681ffe50 r14:0x3f48fc r15:0x7f95a596f040 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x12a fs_base:0x7f95a56cb740 gs_base:0x0
}
{
  real_time:273919.901176 global_time:185, event:`SYSCALL: fcntl' (state:ENTERING_SYSCALL) tid:4147452, ticks:33272
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x64 rsi:0x406 rdi:0x4 rbp:0x681fffa0 rsp:0x681ffd70 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x4 r13:0x681ffe50 r14:0x3f48fc r15:0x7f95a596f040 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x48 fs_base:0x7f95a56cb740 gs_base:0x0
}
{
  real_time:273919.901305 global_time:186, event:`SYSCALL: fcntl' (state:EXITING_SYSCALL) tid:4147452, ticks:33272
rax:0x64 rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x64 rsi:0x406 rdi:0x4 rbp:0x681fffa0 rsp:0x681ffd70 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x4 r13:0x681ffe50 r14:0x3f48fc r15:0x7f95a596f040 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x48 fs_base:0x7f95a56cb740 gs_base:0x0
  { tid:4147452, addr:0x7f95a592c48c, length:0x1 }
}
{
  real_time:273919.901379 global_time:187, event:`SYSCALL: rrcall_init_buffers' (state:ENTERING_SYSCALL) tid:4147452, ticks:33277
rax:0xffffffffffffffda rbx:0x64 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x681ffe50 rbp:0x681fffa0 rsp:0x681ffdd0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x4 r13:0x681ffe50 r14:0x3f48fc r15:0x7f95a596f040 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x3e9 fs_base:0x7f95a56cb740 gs_base:0x0
}
{
  real_time:273919.901732 global_time:188, event:`SYSCALL: rrcall_init_buffers' (state:EXITING_SYSCALL) tid:4147452, ticks:33277
rax:0x7f95a55cb000 rbx:0x64 rcx:0xffffffffffffffff rdx:0x0 rsi:0x0 rdi:0x681ffe50 rbp:0x681fffa0 rsp:0x681ffdd0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x4 r13:0x681ffe50 r14:0x3f48fc r15:0x7f95a596f040 rip:0x70000005 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x3e9 fs_base:0x7f95a56cb740 gs_base:0x0
  { map_file:"<ZERO>", addr:0x7f95a55cb000, length:0x100000, prot_flags:"rw-s", file_offset:0x0, device:28, inode:1680996, data_file:"", data_offset:0x0, file_size:0x100000 }
  { tid:4147452, addr:0x7f95a592c48c, length:0x1 }
  { tid:4147452, addr:0x681ffe50, length:0x20 }
}
{
  real_time:273919.901813 global_time:189, event:`SYSCALL: pkey_alloc' (state:ENTERING_SYSCALL) tid:4147452, ticks:33285
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x35 rsi:0x0 rdi:0x0 rbp:0x681fffa0 rsp:0x681ffdb0 r8:0x7f95a593b040 r9:0x0 r10:0x7ffdec90c6d4 r11:0x246 r12:0x4 r13:0x681ffe50 r14:0x3f48fc r15:0x7f95a596f040 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x14a fs_base:0x7f95a56cb740 gs_base:0x0
}
{
  real_time:273919.901943 global_time:190, event:`SYSCALL: pkey_alloc' (state:EXITING_SYSCALL) tid:4147452, ticks:33285
rax:0x1 rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x35 rsi:0x0 rdi:0x0 rbp:0x681fffa0 rsp:0x681ffdb0 r8:0x7f95a593b040 r9:0x0 r10:0x7ffdec90c6d4 r11:0x246 r12:0x4 r13:0x681ffe50 r14:0x3f48fc r15:0x7f95a596f040 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x14a fs_base:0x7f95a56cb740 gs_base:0x0 st0:0x0 st1:0x0 st2:0x0 st3:0x0 st4:0x0 st5:0x0 st6:0x0 st7:0x0 ymm0:0x0 ymm1:0x0 ymm2:0x0 ymm3:0x6b636f ymm4:0x616e7265746e695f666f747274735f5f ymm5:0xd98 ymm6:0x60 ymm7:0x1 ymm8:0x0 ymm9:0x0 ymm10:0x0 ymm11:0x0 ymm12:0x0 ymm13:0x0 ymm14:0x0 ymm15:0x0
}
{
  real_time:273919.902049 global_time:191, event:`PATCH_SYSCALL' tid:4147452, ticks:33295
rax:0x9 rbx:0x0 rcx:0xffffffffffffffff rdx:0x3 rsi:0x1000 rdi:0x0 rbp:0x7ffdec90c6f0 rsp:0x7ffdec90c6b8 r8:0xffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x7ffdec90c808 r13:0x56474160850d r14:0x56474160ad78 r15:0x7f95a596f040 rip:0x7f95a57ecbd5 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7f95a56cb740 gs_base:0x0
  { tid:4147452, addr:0x7f95a58f705e, length:0x5e }
  { tid:4147452, addr:0x7f95a57ecbd5, length:0x8 }
}
{
  real_time:273919.902105 global_time:192, event:`SYSCALL: mmap' (state:ENTERING_SYSCALL) tid:4147452, ticks:33304
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x3 rsi:0x1000 rdi:0x0 rbp:0x681fffa0 rsp:0x681ffdb0 r8:0xffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x7ffdec90c808 r13:0x56474160850d r14:0x56474160ad78 r15:0x7f95a596f040 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0x7f95a56cb740 gs_base:0x0
}
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackEv+0x60)[0x559f279952c5]
rr(_ZN2rr9GdbServer15emergency_debugEPNS_4TaskE+0xfb)[0x559f2777f53d]
rr(+0x403f6f)[0x559f277baf6f]
rr(_ZN2rr21EmergencyDebugOstreamD1Ev+0x63)[0x559f277bb215]
rr(_ZN2rr13ReplaySession23check_ticks_consistencyEPNS_10ReplayTaskERKNS_5EventE+0x143)[0x559f278cbd25]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x8fb)[0x559f278d021f]
rr(_ZN2rr13ReplaySession11replay_stepENS_10RunCommandE+0x4f)[0x559f278c4ce7]
rr(+0x50c17b)[0x559f278c317b]
rr(+0x50c99f)[0x559f278c399f]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x41f)[0x559f278c4921]
rr(main+0x278)[0x559f279b3d54]
/lib/x86_64-linux-gnu/libc.so.6(+0x29d90)[0x7f7b347b4d90]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x80)[0x7f7b347b4e40]
rr(_start+0x25)[0x559f276c1735]
=== End rr backtrace
process 4147454 sent SIGURG
====== /proc/4147454/status
Name:   rr
Umask:  0002
State:  S (sleeping)
Tgid:   4147454
Ngid:   0
Pid:    4147454
PPid:   4147453
TracerPid:  0
Uid:    1000    1000    1000    1000
Gid:    1000    1000    1000    1000
FDSize: 64
Groups: 4 20 24 27 30 44 46 122 133 134 136 137 140 998 1000 
NStgid: 4147454
NSpid:  4147454
NSpgid: 4147454
NSsid:  3710389
VmPeak:    17720 kB
VmSize:    16744 kB
VmLck:         0 kB
VmPin:         0 kB
VmHWM:      8444 kB
VmRSS:      8444 kB
RssAnon:         896 kB
RssFile:        7548 kB
RssShmem:          0 kB
VmData:      840 kB
VmStk:       132 kB
VmExe:      3292 kB
VmLib:      4056 kB
VmPTE:        72 kB
VmSwap:        0 kB
HugetlbPages:          0 kB
CoreDumping:    0
THP_enabled:    1
Threads:    1
SigQ:   1/126852
SigPnd: 0000000000000000
ShdPnd: 0000000000000000
SigBlk: 0000000000000000
SigIgn: 0000000180000000
SigCgt: 0000000000002000
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:   2000
Cpus_allowed_list:  13
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:    245
nonvoluntary_ctxt_switches: 3
====== /proc/4147454/stack
====== /proc/4147455/status
Name:   rr:pkeys-oIqUMu
Umask:  0002
State:  t (tracing stop)
Tgid:   4147455
Ngid:   0
Pid:    4147455
PPid:   4147454
TracerPid:  4147454
Uid:    1000    1000    1000    1000
Gid:    1000    1000    1000    1000
FDSize: 1024
Groups: 4 20 24 27 30 44 46 122 133 134 136 137 140 998 1000 
NStgid: 4147455
NSpid:  4147455
NSpgid: 4147455
NSsid:  4147455
VmPeak:     5796 kB
VmSize:     5796 kB
VmLck:         0 kB
VmPin:         0 kB
VmHWM:      1136 kB
VmRSS:      1136 kB
RssAnon:         296 kB
RssFile:         840 kB
RssShmem:          0 kB
VmData:     2304 kB
VmStk:         0 kB
VmExe:         4 kB
VmLib:      1840 kB
VmPTE:        60 kB
VmSwap:        0 kB
HugetlbPages:          0 kB
CoreDumping:    0
THP_enabled:    1
Threads:    1
SigQ:   1/126852
SigPnd: 0000000000000000
ShdPnd: 0000000000000000
SigBlk: 0000000000000000
SigIgn: 0000000180010000
SigCgt: 0000000000000000
CapInh: 0000000000000000
CapPrm: 0000000000000000
CapEff: 0000000000000000
CapBnd: 000001ffffffffff
CapAmb: 0000000000000000
NoNewPrivs: 1
Seccomp:    0
Seccomp_filters:    0
Speculation_Store_Bypass:   thread vulnerable
SpeculationIndirectBranch:  conditional enabled
Cpus_allowed:   2000
Cpus_allowed_list:  13
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:    244
nonvoluntary_ctxt_switches: 0
====== /proc/4147455/stack
====== gdb -p 4147454 -ex 'set confirm off' -ex 'set height 0' -ex 'thread apply all bt' -ex q </dev/null 2>&1
GNU gdb (Ubuntu 12.0.90-0ubuntu1) 12.0.90
Copyright (C) 2022 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-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".
GEF for linux ready, type `gef' to start, `gef config' to configure
95 commands loaded for GDB 12.0.90 using Python engine 3.10
[*] 1 command could not be loaded, run `gef missing` to know why.
Attaching to process 4147454
Could not attach to process.  If your uid matches the uid of the target
process, check the setting of /proc/sys/kernel/yama/ptrace_scope, or try
again as the root user.  For more details, see /etc/sysctl.d/10-ptrace.conf
ptrace: Inappropriate ioctl for device.
BFD: warning: system-supplied DSO at 0x6fffd000 has a section extending past end of file
26  ../sysdeps/unix/sysv/linux/write.c: No such file or directory.
[FATAL src/log.cc:449:emergency_debug()] Can't resume execution from invalid state
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackEv+0x60)[0x559f279952c5]
rr(_ZN2rr15notifying_abortEv+0x16)[0x559f2799521e]
rr(_ZN2rr12FatalOstreamD1Ev+0x31)[0x559f277babd1]
rr(+0x403fbc)[0x559f277bafbc]
rr(_ZN2rr21EmergencyDebugOstreamD1Ev+0x63)[0x559f277bb215]
rr(_ZN2rr13ReplaySession23check_ticks_consistencyEPNS_10ReplayTaskERKNS_5EventE+0x143)[0x559f278cbd25]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x8fb)[0x559f278d021f]
rr(_ZN2rr13ReplaySession11replay_stepENS_10RunCommandE+0x4f)[0x559f278c4ce7]
rr(+0x50c17b)[0x559f278c317b]
rr(+0x50c99f)[0x559f278c399f]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x41f)[0x559f278c4921]
rr(main+0x278)[0x559f279b3d54]
/lib/x86_64-linux-gnu/libc.so.6(+0x29d90)[0x7f7b347b4d90]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x80)[0x7f7b347b4e40]
rr(_start+0x25)[0x559f276c1735]
=== End rr backtrace
GNU gdb (Ubuntu 12.0.90-0ubuntu1) 12.0.90
Copyright (C) 2022 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-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"...
GEF for linux ready, type `gef' to start, `gef config' to configure
95 commands loaded for GDB 12.0.90 using Python engine 3.10
[*] 1 command could not be loaded, run `gef missing` to know why.
Reading symbols from /tmp/rr-test-pkeys-oIqUMuaOz/pkeys-oIqUMuaOz-0/mmap_hardlink_4_pkeys-oIqUMuaOz...
Remote debugging using 127.0.0.1:18687
Reading symbols from /home/russ/work/rr/obj/lib/rr/librrpreload.so...
Reading symbols from /lib/x86_64-linux-gnu/libc.so.6...
Reading symbols from /usr/lib/debug/.build-id/69/389d485a9793dbe873f0ea2c93e02efaa9aa3d.debug...
Reading symbols from /lib64/ld-linux-x86-64.so.2...
Reading symbols from /usr/lib/debug/.build-id/61/ef896a699bb1c2e4e231642b2e1688b2f1a61e.debug...
0x00007f95a57e2a35 in __GI___libc_write (fd=0x1, buf=0x7ffdec90c1b0, nbytes=0x80) at ../sysdeps/unix/sysv/linux/write.c:26
[ Legend: Modified register | Code | Heap | Stack | String ]
───────────────────────────────────────────────────────────────────────────────────── registers ────
$rax   : 0x1               
$rbx   : 0x007f95a58a68a2  →  0x73736563637553 ("Success"?)
$rcx   : 0xffffffffffffffff
$rdx   : 0x80              
$rsp   : 0x007ffdec90c178  →  0x00564741608346  →  <atomic_printf+221> mov rdx, QWORD PTR [rbp-0xb8]
$rbp   : 0x007ffdec90c670  →  0x007ffdec90c6b0  →  0x007ffdec90c6f0  →  0x0000000000000001
$rsi   : 0x007ffdec90c1b0  →  "FAILED at src/test/x86/pkeys.c:69: !((initial_pkru[...]"
$rdi   : 0x1               
$rip   : 0x007f95a57e2a35  →  <write+21> syscall 
$r8    : 0x007f95a589f460  →  0x0000000000000000
$r9    : 0x007ffdec90c0f0  →  0x0000000000000000
$r10   : 0x0               
$r11   : 0x246             
$r12   : 0x007ffdec90c808  →  0x007ffdec90d2ea  →  "./pkeys-oIqUMuaOz"
$r13   : 0x0056474160850d  →  <main+0> endbr64 
$r14   : 0x0056474160ad78  →  0x00564741608220  →  <__do_global_dtors_aux+0> endbr64 
$r15   : 0x007f95a596f040  →  0x007f95a59702e0  →  0x00564741607000  →  0x00010102464c457f
$eflags: [ZERO carry PARITY adjust sign trap INTERRUPT direction overflow resume virtualx86 identification]
$cs: 0x33 $ss: 0x2b $ds: 0x00 $es: 0x00 $fs: 0x00 $gs: 0x00 
───────────────────────────────────────────────────────────────────────────────────────── stack ────
0x007ffdec90c178│+0x0000: 0x00564741608346  →  <atomic_printf+221> mov rdx, QWORD PTR [rbp-0xb8]     ← $rsp
0x007ffdec90c180│+0x0008: 0x0000000000000000
0x007ffdec90c188│+0x0010: 0x00564741609010  →  "FAILED at %s:%d: !(%s) errno:%d (%s)\n"
0x007ffdec90c190│+0x0018: 0x0000008000000000
0x007ffdec90c198│+0x0020: 0x00003000000030 ("0"?)
0x007ffdec90c1a0│+0x0028: 0x007ffdec90c680  →  0x0000000000000000
0x007ffdec90c1a8│+0x0030: 0x007ffdec90c5c0  →  0x0000000000000000
0x007ffdec90c1b0│+0x0038: "FAILED at src/test/x86/pkeys.c:69: !((initial_pkru[...]"   ← $rsi
─────────────────────────────────────────────────────────────────────────────────── code:x86:64 ────
   0x7f95a57e2a2c <write+12>       test   eax, eax
   0x7f95a57e2a2e <write+14>       jne    0x7f95a57e2a40 <__GI___libc_write+32>
   0x7f95a57e2a30 <write+16>       mov    eax, 0x1
 → 0x7f95a57e2a35 <write+21>       syscall 
   0x7f95a57e2a37 <write+23>       cmp    rax, 0xfffffffffffff000
   0x7f95a57e2a3d <write+29>       ja     0x7f95a57e2a90 <__GI___libc_write+112>
   0x7f95a57e2a3f <write+31>       ret    
   0x7f95a57e2a40 <write+32>       sub    rsp, 0x28
   0x7f95a57e2a44 <write+36>       mov    QWORD PTR [rsp+0x18], rdx
─────────────────────────────────────────────────────────────────────────────────────── threads ────
[#0] Id 1, stopped 0x7f95a57e2a35 in __GI___libc_write (), reason: STOPPED
───────────────────────────────────────────────────────────────────────────────────────── trace ────
[#0] 0x7f95a57e2a35 → __GI___libc_write(fd=0x1, buf=0x7ffdec90c1b0, nbytes=0x80)
[#1] 0x564741608346 → atomic_printf(fmt=0x564741609010 "FAILED at %s:%d: !(%s) errno:%d (%s)\n")
[#2] 0x5647416083e5 → atomic_assert(cond=0x0, str=0x564741609128 "(initial_pkru & ~(PKEY_DISABLE_ACCESS << (2 * pkey ))) == modified_pkru", file=0x564741609072 "src/test/x86/pkeys.c", line=0x45)
[#3] 0x5647416086e4 → main()
────────────────────────────────────────────────────────────────────────────────────────────────────
rax            0x1                 0x1
rbx            0x7f95a58a68a2      0x7f95a58a68a2
rcx            0xffffffffffffffff  0xffffffffffffffff
rdx            0x80                0x80
rsi            0x7ffdec90c1b0      0x7ffdec90c1b0
rdi            0x1                 0x1
rbp            0x7ffdec90c670      0x7ffdec90c670
rsp            0x7ffdec90c178      0x7ffdec90c178
r8             0x7f95a589f460      0x7f95a589f460
r9             0x7ffdec90c0f0      0x7ffdec90c0f0
r10            0x0                 0x0
r11            0x246               0x246
r12            0x7ffdec90c808      0x7ffdec90c808
r13            0x56474160850d      0x56474160850d
r14            0x56474160ad78      0x56474160ad78
r15            0x7f95a596f040      0x7f95a596f040
rip            0x7f95a57e2a35      0x7f95a57e2a35 <__GI___libc_write+21>
eflags         0x246               [ PF ZF IF ]
cs             0x33                0x33
ss             0x2b                0x2b
ds             0x0                 0x0
es             0x0                 0x0
fs             0x0                 0x0
gs             0x0                 0x0

Thread 1 (Thread 4147452.4147452 (pkeys-oIqUMuaOz)):
#0  0x00007f95a57e2a35 in __GI___libc_write (fd=0x1, buf=0x7ffdec90c1b0, nbytes=0x80) at ../sysdeps/unix/sysv/linux/write.c:26
#1  0x0000564741608346 in atomic_printf (fmt=0x564741609010 "FAILED at %s:%d: !(%s) errno:%d (%s)\n") at /home/russ/work/rr/src/test/x86/../util.h:168
#2  0x00005647416083e5 in atomic_assert (cond=0x0, str=0x564741609128 "(initial_pkru & ~(PKEY_DISABLE_ACCESS << (2 * pkey ))) == modified_pkru", file=0x564741609072 "src/test/x86/pkeys.c", line=0x45) at /home/russ/work/rr/src/test/x86/../util.h:187
#3  0x00005647416086e4 in main () at /home/russ/work/rr/src/test/x86/pkeys.c:69
Detaching from program: /tmp/rr-test-pkeys-oIqUMuaOz/pkeys-oIqUMuaOz-0/mmap_hardlink_4_pkeys-oIqUMuaOz, process 4147452
[Inferior 1 (process 4147452) detached]
--------------------------------------------------
replay.out:
--------------------------------------------------
--------------------------------------------------
Test pkeys failed, leaving behind /tmp/rr-test-pkeys-oIqUMuaOz
To replay the failed test, run
  _RR_TRACE_DIR=/tmp/rr-test-pkeys-oIqUMuaOz rr replay
<end of output>
Test time =   2.61 sec
----------------------------------------------------------
Test Fail Reason:
Error regular expression found in output. Regex=[FAILED]
"x86/pkeys" end time: Sep 26 13:29 CEST
"x86/pkeys" time elapsed: 00:00:02
----------------------------------------------------------

461/2841 Testing: x86/pkeys-no-syscallbuf
461/2841 Test: x86/pkeys-no-syscallbuf
Command: "/usr/bin/bash" "source_dir/src/test/basic_test.run" "pkeys" "-n" "bin_dir" "120"
Directory: /home/russ/work/rr/obj
"x86/pkeys-no-syscallbuf" start time: Sep 26 13:29 CEST
Output:
----------------------------------------------------------
source_dir/src/test/util.sh: line 287: 4147687 Aborted                 (core dumped) _RR_TRACE_DIR="$workdir" test-monitor $TIMEOUT replay.err $RR_EXE $GLOBAL_OPTIONS replay -a $replayflags > replay.out 2> replay.err
Test 'pkeys' FAILED: : error during replay:
--------------------------------------------------
[FATAL src/ReplaySession.cc:635:enter_syscall()] 
 (task 4147689 (rec:4147686) at time 180)
 -> Assertion `false' failed to hold. Expected syscall_bp_vm to be clear but it's 4147686's address space with a breakpoint at 0x7fcc5e510bd5 while we're at 0x7fcc5e506a37
Tail of trace dump:
{
  real_time:273922.509836 global_time:160, event:`SYSCALL: rseq' (state:EXITING_SYSCALL) tid:4147686, ticks:18237
rax:0x0 rbx:0x7fcc5e3f00e0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x20 rdi:0x7fcc5e3f00e0 rbp:0x0 rsp:0x7ffeff63c510 r8:0x0 r9:0x0 r10:0x53053053 r11:0x246 r12:0x7fcc5e3ef740 r13:0x7ffeff63c550 r14:0x0 r15:0x7fcc5e6942e0 rip:0x7fcc5e66e1d1 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x14e fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.509904 global_time:161, event:`INSTRUCTION_TRAP' tid:4147686, ticks:18264
rax:0x1d7896db rbx:0x0 rcx:0x0 rdx:0x23e05 rsi:0x7ffeff63d2ff rdi:0x7fcc5e6942e0 rbp:0x7ffeff63c820 rsp:0x7ffeff63c550 r8:0xf r9:0x7ffeff63d2ff r10:0x0 r11:0x246 r12:0x0 r13:0x7ffeff63c550 r14:0x7fcc5e3ef740 r15:0x7fcc5e6942e0 rip:0x7fcc5e67c9e8 eflags:0x10202 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.509999 global_time:162, event:`SYSCALL: mprotect' (state:ENTERING_SYSCALL) tid:4147686, ticks:28663
rax:0xffffffffffffffda rbx:0x7fcc5e419fe0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x4000 rdi:0x7fcc5e607000 rbp:0x7ffeff63c540 rsp:0x7ffeff63c438 r8:0x7fcc5e3f8e58 r9:0x0 r10:0x7fcc5e3f2000 r11:0x246 r12:0x7fcc5e3f2000 r13:0x7fcc5e657a10 r14:0x7fcc5e657a10 r15:0x7fcc5e419fc8 rip:0x7fcc5e67fd4b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xa fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.510120 global_time:163, event:`SYSCALL: mprotect' (state:EXITING_SYSCALL) tid:4147686, ticks:28663
rax:0x0 rbx:0x7fcc5e419fe0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x4000 rdi:0x7fcc5e607000 rbp:0x7ffeff63c540 rsp:0x7ffeff63c438 r8:0x7fcc5e3f8e58 r9:0x0 r10:0x7fcc5e3f2000 r11:0x246 r12:0x7fcc5e3f2000 r13:0x7fcc5e657a10 r14:0x7fcc5e657a10 r15:0x7fcc5e419fc8 rip:0x7fcc5e67fd4b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xa fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.510193 global_time:164, event:`SYSCALL: mprotect' (state:ENTERING_SYSCALL) tid:4147686, ticks:29048
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x1000 rdi:0x7fcc5e64f000 rbp:0x7ffeff63c540 rsp:0x7ffeff63c438 r8:0x7fcc5e6453f0 r9:0x7fcc5e646657 r10:0x7fcc5e645000 r11:0x246 r12:0x7fcc5e645c50 r13:0x7fcc5e650048 r14:0x7fcc5e6574e0 r15:0x0 rip:0x7fcc5e67fd4b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xa fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.510313 global_time:165, event:`SYSCALL: mprotect' (state:EXITING_SYSCALL) tid:4147686, ticks:29048
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x1000 rdi:0x7fcc5e64f000 rbp:0x7ffeff63c540 rsp:0x7ffeff63c438 r8:0x7fcc5e6453f0 r9:0x7fcc5e646657 r10:0x7fcc5e645000 r11:0x246 r12:0x7fcc5e645c50 r13:0x7fcc5e650048 r14:0x7fcc5e6574e0 r15:0x0 rip:0x7fcc5e67fd4b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xa fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.510388 global_time:166, event:`SYSCALL: mprotect' (state:ENTERING_SYSCALL) tid:4147686, ticks:30475
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x1000 rdi:0x55be61f6d000 rbp:0x7ffeff63c540 rsp:0x7ffeff63c438 r8:0x7fcc5e3fe888 r9:0x7fcc5e42c360 r10:0x55be61f6a000 r11:0x246 r12:0x0 r13:0x55be61f6a528 r14:0x7fcc5e6942e0 r15:0x7fcc5e6942e0 rip:0x7fcc5e67fd4b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xa fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.510509 global_time:167, event:`SYSCALL: mprotect' (state:EXITING_SYSCALL) tid:4147686, ticks:30475
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x1000 rdi:0x55be61f6d000 rbp:0x7ffeff63c540 rsp:0x7ffeff63c438 r8:0x7fcc5e3fe888 r9:0x7fcc5e42c360 r10:0x55be61f6a000 r11:0x246 r12:0x0 r13:0x55be61f6a528 r14:0x7fcc5e6942e0 r15:0x7fcc5e6942e0 rip:0x7fcc5e67fd4b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xa fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.510576 global_time:168, event:`INSTRUCTION_TRAP' tid:4147686, ticks:30479
rax:0x1d903737 rbx:0x0 rcx:0xffffffffffffffff rdx:0x23e05 rsi:0x1000 rdi:0x55be61f6d000 rbp:0x7ffeff63c820 rsp:0x7ffeff63c550 r8:0x7fcc5e3fe888 r9:0x7fcc5e42c360 r10:0x55be61f6a000 r11:0x246 r12:0x7fcc5e6942e0 r13:0xfffffffffffffff8 r14:0x7fcc5e3ef740 r15:0x7fcc5e6942e0 rip:0x7fcc5e67cac0 eflags:0x10246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.510628 global_time:169, event:`INSTRUCTION_TRAP' tid:4147686, ticks:31020
rax:0x1d92114d rbx:0x0 rcx:0x0 rdx:0x23e05 rsi:0x7fcc5e687929 rdi:0x7fcc5e4103d8 rbp:0x7ffeff63c820 rsp:0x7ffeff63c550 r8:0xffff r9:0xf r10:0xfffffffffffff9bf r11:0x0 r12:0x7fcc5e6942e0 r13:0xfffffffffffffff8 r14:0x7fcc5e3ef740 r15:0x7fcc5e6942e0 rip:0x7fcc5e67d208 eflags:0x10206 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.510682 global_time:170, event:`SYSCALL: mprotect' (state:ENTERING_SYSCALL) tid:4147686, ticks:31671
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x2000 rdi:0x7fcc5e691000 rbp:0x7ffeff63c540 rsp:0x7ffeff63c438 r8:0x7fcc5e3f9e60 r9:0x0 r10:0x7fcc5e659000 r11:0x246 r12:0x0 r13:0x0 r14:0x7fcc5e693af0 r15:0x7fcc5e693af0 rip:0x7fcc5e67fd4b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xa fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.510809 global_time:171, event:`SYSCALL: mprotect' (state:EXITING_SYSCALL) tid:4147686, ticks:31671
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x2000 rdi:0x7fcc5e691000 rbp:0x7ffeff63c540 rsp:0x7ffeff63c438 r8:0x7fcc5e3f9e60 r9:0x0 r10:0x7fcc5e659000 r11:0x246 r12:0x0 r13:0x0 r14:0x7fcc5e693af0 r15:0x7fcc5e693af0 rip:0x7fcc5e67fd4b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xa fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.510877 global_time:172, event:`INSTRUCTION_TRAP' tid:4147686, ticks:31673
rax:0x1d9ad31b rbx:0x23e051d92114d rcx:0xffffffffffffffff rdx:0x23e05 rsi:0x2000 rdi:0x7fcc5e691000 rbp:0x7ffeff63c820 rsp:0x7ffeff63c550 r8:0x7fcc5e3f9e60 r9:0x0 r10:0x7fcc5e659000 r11:0x246 r12:0x7fcc5e6942e0 r13:0xfffffffffffffff8 r14:0x7fcc5e3ef740 r15:0x7fcc5e6942e0 rip:0x7fcc5e67d232 eflags:0x10246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.510942 global_time:173, event:`SYSCALL: prlimit64' (state:ENTERING_SYSCALL) tid:4147686, ticks:31696
rax:0xffffffffffffffda rbx:0x1 rcx:0xffffffffffffffff rdx:0x0 rsi:0x3 rdi:0x0 rbp:0x7ffeff63c820 rsp:0x7ffeff63c518 r8:0x0 r9:0xf r10:0x7ffeff63c520 r11:0x246 r12:0x7fcc5e6942e0 r13:0xfffffffffffffff8 r14:0x7fcc5e3ef740 r15:0x7fcc5e6942e0 rip:0x7fcc5e50c494 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x12e fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.511064 global_time:174, event:`SYSCALL: prlimit64' (state:EXITING_SYSCALL) tid:4147686, ticks:31696
rax:0x0 rbx:0x1 rcx:0xffffffffffffffff rdx:0x0 rsi:0x3 rdi:0x0 rbp:0x7ffeff63c820 rsp:0x7ffeff63c518 r8:0x0 r9:0xf r10:0x7ffeff63c520 r11:0x246 r12:0x7fcc5e6942e0 r13:0xfffffffffffffff8 r14:0x7fcc5e3ef740 r15:0x7fcc5e6942e0 rip:0x7fcc5e50c494 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x12e fs_base:0x7fcc5e3ef740 gs_base:0x0
  { tid:4147686, addr:0x7ffeff63c520, length:0x10 }
}
{
  real_time:273922.511145 global_time:175, event:`SYSCALL: munmap' (state:ENTERING_SYSCALL) tid:4147686, ticks:31831
rax:0xffffffffffffffda rbx:0x7fcc5e694118 rcx:0xffffffffffffffff rdx:0x7fcc5e482c90 rsi:0x2a51b rdi:0x7fcc5e61a000 rbp:0x7ffeff63c820 rsp:0x7ffeff63c538 r8:0x0 r9:0xf r10:0x7fcc5e659860 r11:0x246 r12:0x7fcc5e6942e0 r13:0xfffffffffffffff8 r14:0x7fcc5e3ef740 r15:0x7fcc5e6942e0 rip:0x7fcc5e67fd1b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.511272 global_time:176, event:`SYSCALL: munmap' (state:EXITING_SYSCALL) tid:4147686, ticks:31831
rax:0x0 rbx:0x7fcc5e694118 rcx:0xffffffffffffffff rdx:0x7fcc5e482c90 rsi:0x2a51b rdi:0x7fcc5e61a000 rbp:0x7ffeff63c820 rsp:0x7ffeff63c538 r8:0x0 r9:0xf r10:0x7fcc5e659860 r11:0x246 r12:0x7fcc5e6942e0 r13:0xfffffffffffffff8 r14:0x7fcc5e3ef740 r15:0x7fcc5e6942e0 rip:0x7fcc5e67fd1b eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xb fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.511362 global_time:177, event:`INSTRUCTION_TRAP' tid:4147686, ticks:33015
rax:0x2 rbx:0xf3bba7eb rcx:0x18c05fde rdx:0xfc100510 rsi:0x0 rdi:0x7 rbp:0x7ffeff63c840 rsp:0x7ffeff63c838 r8:0x7ffeff63c864 r9:0x7fcc5e65f040 r10:0x7fcc5e659908 r11:0x7fcc5e674680 r12:0x7ffeff63c998 r13:0x55be61f6b50d r14:0x55be61f6dd78 r15:0x7fcc5e693040 rip:0x55be61f6b46a eflags:0x10246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.511418 global_time:178, event:`SYSCALL: pkey_alloc' (state:ENTERING_SYSCALL) tid:4147686, ticks:33017
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x35 rsi:0x0 rdi:0x0 rbp:0x7ffeff63c880 rsp:0x7ffeff63c848 r8:0x7fcc5e65f040 r9:0x0 r10:0x7ffeff63c864 r11:0x246 r12:0x7ffeff63c998 r13:0x55be61f6b50d r14:0x55be61f6dd78 r15:0x7fcc5e693040 rip:0x7fcc5e510a3d eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x14a fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.511544 global_time:179, event:`SYSCALL: pkey_alloc' (state:EXITING_SYSCALL) tid:4147686, ticks:33017
rax:0x1 rbx:0x0 rcx:0xffffffffffffffff rdx:0x35 rsi:0x0 rdi:0x0 rbp:0x7ffeff63c880 rsp:0x7ffeff63c848 r8:0x7fcc5e65f040 r9:0x0 r10:0x7ffeff63c864 r11:0x246 r12:0x7ffeff63c998 r13:0x55be61f6b50d r14:0x55be61f6dd78 r15:0x7fcc5e693040 rip:0x7fcc5e510a3d eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x14a fs_base:0x7fcc5e3ef740 gs_base:0x0 st0:0x0 st1:0x0 st2:0x0 st3:0x0 st4:0x0 st5:0x0 st6:0x0 st7:0x0 ymm0:0x0 ymm1:0x0 ymm2:0x0 ymm3:0x6b636f ymm4:0x616e7265746e695f666f747274735f5f ymm5:0xd98 ymm6:0x60 ymm7:0x1 ymm8:0x0 ymm9:0x0 ymm10:0x0 ymm11:0x0 ymm12:0x0 ymm13:0x0 ymm14:0x0 ymm15:0x0
}
{
  real_time:273922.511639 global_time:180, event:`SYSCALL: mmap' (state:ENTERING_SYSCALL) tid:4147686, ticks:33024
rax:0xffffffffffffffda rbx:0x0 rcx:0xffffffffffffffff rdx:0x3 rsi:0x1000 rdi:0x0 rbp:0x7ffeff63c880 rsp:0x7ffeff63c848 r8:0xffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x7ffeff63c998 r13:0x55be61f6b50d r14:0x55be61f6dd78 r15:0x7fcc5e693040 rip:0x7fcc5e510bd7 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0x7fcc5e3ef740 gs_base:0x0
}
{
  real_time:273922.511766 global_time:181, event:`SYSCALL: mmap' (state:EXITING_SYSCALL) tid:4147686, ticks:33024
rax:0x7fcc5e690000 rbx:0x0 rcx:0xffffffffffffffff rdx:0x3 rsi:0x1000 rdi:0x0 rbp:0x7ffeff63c880 rsp:0x7ffeff63c848 r8:0xffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x7ffeff63c998 r13:0x55be61f6b50d r14:0x55be61f6dd78 r15:0x7fcc5e693040 rip:0x7fcc5e510bd7 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0x7fcc5e3ef740 gs_base:0x0
  { map_file:"<ZERO>", addr:0x7fcc5e690000, length:0x1000, prot_flags:"rw-p", file_offset:0x0, device:0, inode:0, data_file:"", data_offset:0x0, file_size:0x1000 }
}
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackEv+0x60)[0x555bceef22c5]
rr(_ZN2rr9GdbServer15emergency_debugEPNS_4TaskE+0xfb)[0x555bcecdc53d]
rr(+0x403f6f)[0x555bced17f6f]
rr(_ZN2rr21EmergencyDebugOstreamD1Ev+0x63)[0x555bced18215]
rr(_ZN2rr13ReplaySession13enter_syscallEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0x63d)[0x555bcee261b1]
rr(_ZN2rr13ReplaySession18try_one_trace_stepEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0x127)[0x555bcee2b249]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x1d7)[0x555bcee2cafb]
rr(_ZN2rr13ReplaySession11replay_stepENS_10RunCommandE+0x4f)[0x555bcee21ce7]
rr(+0x50c17b)[0x555bcee2017b]
rr(+0x50c99f)[0x555bcee2099f]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x41f)[0x555bcee21921]
rr(main+0x278)[0x555bcef10d54]
/lib/x86_64-linux-gnu/libc.so.6(+0x29d90)[0x7fb00ec40d90]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x80)[0x7fb00ec40e40]
rr(_start+0x25)[0x555bcec1e735]
=== End rr backtrace
process 4147688 sent SIGURG
====== /proc/4147688/status
Name:   rr
Umask:  0002
State:  S (sleeping)
Tgid:   4147688
Ngid:   0
Pid:    4147688
PPid:   4147687
TracerPid:  0
Uid:    1000    1000    1000    1000
Gid:    1000    1000    1000    1000
FDSize: 64
Groups: 4 20 24 27 30 44 46 122 133 134 136 137 140 998 1000 
NStgid: 4147688
NSpid:  4147688
NSpgid: 4147688
NSsid:  3710389
VmPeak:    16688 kB
VmSize:    15716 kB
VmLck:         0 kB
VmPin:         0 kB
VmHWM:      8728 kB
VmRSS:      8204 kB
RssAnon:         896 kB
RssFile:        7308 kB
RssShmem:          0 kB
VmData:      836 kB
VmStk:       132 kB
VmExe:      3292 kB
VmLib:      4056 kB
VmPTE:        68 kB
VmSwap:        0 kB
HugetlbPages:          0 kB
CoreDumping:    0
THP_enabled:    1
Threads:    1
SigQ:   1/126852
SigPnd: 0000000000000000
ShdPnd: 0000000000000000
SigBlk: 0000000000000000
SigIgn: 0000000180000000
SigCgt: 0000000000002000
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:   0800
Cpus_allowed_list:  11
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:    233
nonvoluntary_ctxt_switches: 2
====== /proc/4147688/stack
====== /proc/4147689/status
Name:   rr:pkeys-lewItI
Umask:  0002
State:  t (tracing stop)
Tgid:   4147689
Ngid:   0
Pid:    4147689
PPid:   4147688
TracerPid:  4147688
Uid:    1000    1000    1000    1000
Gid:    1000    1000    1000    1000
FDSize: 1024
Groups: 4 20 24 27 30 44 46 122 133 134 136 137 140 998 1000 
NStgid: 4147689
NSpid:  4147689
NSpgid: 4147689
NSsid:  4147689
VmPeak:     4940 kB
VmSize:     4768 kB
VmLck:         0 kB
VmPin:         0 kB
VmHWM:      1116 kB
VmRSS:      1116 kB
RssAnon:         288 kB
RssFile:         828 kB
RssShmem:          0 kB
VmData:     2304 kB
VmStk:         0 kB
VmExe:         4 kB
VmLib:      1836 kB
VmPTE:        56 kB
VmSwap:        0 kB
HugetlbPages:          0 kB
CoreDumping:    0
THP_enabled:    1
Threads:    1
SigQ:   1/126852
SigPnd: 0000000000000000
ShdPnd: 0000000000000000
SigBlk: 0000000000000000
SigIgn: 0000000180010000
SigCgt: 0000000000000000
CapInh: 0000000000000000
CapPrm: 0000000000000000
CapEff: 0000000000000000
CapBnd: 000001ffffffffff
CapAmb: 0000000000000000
NoNewPrivs: 1
Seccomp:    0
Seccomp_filters:    0
Speculation_Store_Bypass:   thread vulnerable
SpeculationIndirectBranch:  conditional enabled
Cpus_allowed:   0800
Cpus_allowed_list:  11
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:    232
nonvoluntary_ctxt_switches: 0
====== /proc/4147689/stack
====== gdb -p 4147688 -ex 'set confirm off' -ex 'set height 0' -ex 'thread apply all bt' -ex q </dev/null 2>&1
GNU gdb (Ubuntu 12.0.90-0ubuntu1) 12.0.90
Copyright (C) 2022 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-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".
GEF for linux ready, type `gef' to start, `gef config' to configure
95 commands loaded for GDB 12.0.90 using Python engine 3.10
[*] 1 command could not be loaded, run `gef missing` to know why.
Attaching to process 4147688
Could not attach to process.  If your uid matches the uid of the target
process, check the setting of /proc/sys/kernel/yama/ptrace_scope, or try
again as the root user.  For more details, see /etc/sysctl.d/10-ptrace.conf
ptrace: Inappropriate ioctl for device.
BFD: warning: system-supplied DSO at 0x6fffd000 has a section extending past end of file
26  ../sysdeps/unix/sysv/linux/write.c: No such file or directory.
[FATAL src/log.cc:449:emergency_debug()] Can't resume execution from invalid state
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackEv+0x60)[0x555bceef22c5]
rr(_ZN2rr15notifying_abortEv+0x16)[0x555bceef221e]
rr(_ZN2rr12FatalOstreamD1Ev+0x31)[0x555bced17bd1]
rr(+0x403fbc)[0x555bced17fbc]
rr(_ZN2rr21EmergencyDebugOstreamD1Ev+0x63)[0x555bced18215]
rr(_ZN2rr13ReplaySession13enter_syscallEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0x63d)[0x555bcee261b1]
rr(_ZN2rr13ReplaySession18try_one_trace_stepEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0x127)[0x555bcee2b249]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x1d7)[0x555bcee2cafb]
rr(_ZN2rr13ReplaySession11replay_stepENS_10RunCommandE+0x4f)[0x555bcee21ce7]
rr(+0x50c17b)[0x555bcee2017b]
rr(+0x50c99f)[0x555bcee2099f]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x41f)[0x555bcee21921]
rr(main+0x278)[0x555bcef10d54]
/lib/x86_64-linux-gnu/libc.so.6(+0x29d90)[0x7fb00ec40d90]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x80)[0x7fb00ec40e40]
rr(_start+0x25)[0x555bcec1e735]
=== End rr backtrace
GNU gdb (Ubuntu 12.0.90-0ubuntu1) 12.0.90
Copyright (C) 2022 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-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"...
GEF for linux ready, type `gef' to start, `gef config' to configure
95 commands loaded for GDB 12.0.90 using Python engine 3.10
[*] 1 command could not be loaded, run `gef missing` to know why.
Reading symbols from /tmp/rr-test-pkeys-lewItIMxS/pkeys-lewItIMxS-0/mmap_hardlink_4_pkeys-lewItIMxS...
Remote debugging using 127.0.0.1:18921
Reading symbols from /home/russ/work/rr/obj/lib/rr/librrpreload.so...
Reading symbols from /lib/x86_64-linux-gnu/libc.so.6...
Reading symbols from /usr/lib/debug/.build-id/69/389d485a9793dbe873f0ea2c93e02efaa9aa3d.debug...
Reading symbols from /lib64/ld-linux-x86-64.so.2...
Reading symbols from /usr/lib/debug/.build-id/61/ef896a699bb1c2e4e231642b2e1688b2f1a61e.debug...
0x00007fcc5e506a37 in __GI___libc_write (fd=0x1, buf=0x7ffeff63c340, nbytes=0x80) at ../sysdeps/unix/sysv/linux/write.c:26
[ Legend: Modified register | Code | Heap | Stack | String ]
───────────────────────────────────────────────────────────────────────────────────── registers ────
$rax   : 0xffffffffffffffda
$rbx   : 0x007fcc5e5ca8a2  →  0x73736563637553 ("Success"?)
$rcx   : 0x007fcc5e506a37  →  0x5177fffff0003d48 ("H="?)
$rdx   : 0x80              
$rsp   : 0x007ffeff63c308  →  0x0055be61f6b346  →  <atomic_printf+221> mov rdx, QWORD PTR [rbp-0xb8]
$rbp   : 0x007ffeff63c800  →  0x007ffeff63c840  →  0x007ffeff63c880  →  0x0000000000000001
$rsi   : 0x007ffeff63c340  →  "FAILED at src/test/x86/pkeys.c:69: !((initial_pkru[...]"
$rdi   : 0x1               
$rip   : 0x007fcc5e506a37  →  0x5177fffff0003d48 ("H="?)
$r8    : 0x007fcc5e5c3460  →  0x0000000000000000
$r9    : 0x007ffeff63c280  →  "/pkeys-lewItIMxS"
$r10   : 0x0               
$r11   : 0x246             
$r12   : 0x007ffeff63c998  →  0x007ffeff63d2ff  →  "./pkeys-lewItIMxS"
$r13   : 0x0055be61f6b50d  →  <main+0> endbr64 
$r14   : 0x0055be61f6dd78  →  0x0055be61f6b220  →  <__do_global_dtors_aux+0> endbr64 
$r15   : 0x007fcc5e693040  →  0x007fcc5e6942e0  →  0x0055be61f6a000  →  0x00010102464c457f
$eflags: [ZERO carry PARITY adjust sign trap INTERRUPT direction overflow resume virtualx86 identification]
$cs: 0x33 $ss: 0x2b $ds: 0x00 $es: 0x00 $fs: 0x00 $gs: 0x00 
───────────────────────────────────────────────────────────────────────────────────────── stack ────
0x007ffeff63c308│+0x0000: 0x0055be61f6b346  →  <atomic_printf+221> mov rdx, QWORD PTR [rbp-0xb8]     ← $rsp
0x007ffeff63c310│+0x0008: 0x0000000000000000
0x007ffeff63c318│+0x0010: 0x0055be61f6c010  →  "FAILED at %s:%d: !(%s) errno:%d (%s)\n"
0x007ffeff63c320│+0x0018: 0x0000008000000000
0x007ffeff63c328│+0x0020: 0x00003000000030 ("0"?)
0x007ffeff63c330│+0x0028: 0x007ffeff63c810  →  0x0000000000000000
0x007ffeff63c338│+0x0030: 0x007ffeff63c750  →  0x0000000000000000
0x007ffeff63c340│+0x0038: "FAILED at src/test/x86/pkeys.c:69: !((initial_pkru[...]"   ← $rsi
─────────────────────────────────────────────────────────────────────────────────── code:x86:64 ────
   0x7fcc5e506a2e <write+14>       jne    0x7fcc5e506a40 <__GI___libc_write+32>
   0x7fcc5e506a30 <write+16>       mov    eax, 0x1
   0x7fcc5e506a35 <write+21>       syscall 
 → 0x7fcc5e506a37 <write+23>       cmp    rax, 0xfffffffffffff000
   0x7fcc5e506a3d <write+29>       ja     0x7fcc5e506a90 <__GI___libc_write+112>
   0x7fcc5e506a3f <write+31>       ret    
   0x7fcc5e506a40 <write+32>       sub    rsp, 0x28
   0x7fcc5e506a44 <write+36>       mov    QWORD PTR [rsp+0x18], rdx
   0x7fcc5e506a49 <write+41>       mov    QWORD PTR [rsp+0x10], rsi
─────────────────────────────────────────────────────────────────────────────────────── threads ────
[#0] Id 1, stopped 0x7fcc5e506a37 in __GI___libc_write (), reason: STOPPED
───────────────────────────────────────────────────────────────────────────────────────── trace ────
[#0] 0x7fcc5e506a37 → __GI___libc_write(fd=0x1, buf=0x7ffeff63c340, nbytes=0x80)
[#1] 0x55be61f6b346 → atomic_printf(fmt=0x55be61f6c010 "FAILED at %s:%d: !(%s) errno:%d (%s)\n")
[#2] 0x55be61f6b3e5 → atomic_assert(cond=0x0, str=0x55be61f6c128 "(initial_pkru & ~(PKEY_DISABLE_ACCESS << (2 * pkey ))) == modified_pkru", file=0x55be61f6c072 "src/test/x86/pkeys.c", line=0x45)
[#3] 0x55be61f6b6e4 → main()
────────────────────────────────────────────────────────────────────────────────────────────────────
rax            0xffffffffffffffda  0xffffffffffffffda
rbx            0x7fcc5e5ca8a2      0x7fcc5e5ca8a2
rcx            0x7fcc5e506a37      0x7fcc5e506a37
rdx            0x80                0x80
rsi            0x7ffeff63c340      0x7ffeff63c340
rdi            0x1                 0x1
rbp            0x7ffeff63c800      0x7ffeff63c800
rsp            0x7ffeff63c308      0x7ffeff63c308
r8             0x7fcc5e5c3460      0x7fcc5e5c3460
r9             0x7ffeff63c280      0x7ffeff63c280
r10            0x0                 0x0
r11            0x246               0x246
r12            0x7ffeff63c998      0x7ffeff63c998
r13            0x55be61f6b50d      0x55be61f6b50d
r14            0x55be61f6dd78      0x55be61f6dd78
r15            0x7fcc5e693040      0x7fcc5e693040
rip            0x7fcc5e506a37      0x7fcc5e506a37 <__GI___libc_write+23>
eflags         0x246               [ PF ZF IF ]
cs             0x33                0x33
ss             0x2b                0x2b
ds             0x0                 0x0
es             0x0                 0x0
fs             0x0                 0x0
gs             0x0                 0x0

Thread 1 (Thread 4147686.4147686 (pkeys-lewItIMxS)):
#0  0x00007fcc5e506a37 in __GI___libc_write (fd=0x1, buf=0x7ffeff63c340, nbytes=0x80) at ../sysdeps/unix/sysv/linux/write.c:26
#1  0x000055be61f6b346 in atomic_printf (fmt=0x55be61f6c010 "FAILED at %s:%d: !(%s) errno:%d (%s)\n") at /home/russ/work/rr/src/test/x86/../util.h:168
#2  0x000055be61f6b3e5 in atomic_assert (cond=0x0, str=0x55be61f6c128 "(initial_pkru & ~(PKEY_DISABLE_ACCESS << (2 * pkey ))) == modified_pkru", file=0x55be61f6c072 "src/test/x86/pkeys.c", line=0x45) at /home/russ/work/rr/src/test/x86/../util.h:187
#3  0x000055be61f6b6e4 in main () at /home/russ/work/rr/src/test/x86/pkeys.c:69
Detaching from program: /tmp/rr-test-pkeys-lewItIMxS/pkeys-lewItIMxS-0/mmap_hardlink_4_pkeys-lewItIMxS, process 4147686
[Inferior 1 (process 4147686) detached]
--------------------------------------------------
replay.out:
--------------------------------------------------
--------------------------------------------------
Test pkeys failed, leaving behind /tmp/rr-test-pkeys-lewItIMxS
To replay the failed test, run
  _RR_TRACE_DIR=/tmp/rr-test-pkeys-lewItIMxS rr replay
<end of output>
Test time =   2.59 sec
----------------------------------------------------------
Test Fail Reason:
Error regular expression found in output. Regex=[FAILED]
"x86/pkeys-no-syscallbuf" end time: Sep 26 13:29 CEST
"x86/pkeys-no-syscallbuf" time elapsed: 00:00:02
----------------------------------------------------------

1880/2841 Testing: x86/pkeys-32
1880/2841 Test: x86/pkeys-32
Command: "/usr/bin/bash" "source_dir/src/test/basic_test.run" "pkeys_32" "" "bin_dir" "120"
Directory: /home/russ/work/rr/obj
"x86/pkeys-32" start time: Sep 26 13:50 CEST
Output:
----------------------------------------------------------
source_dir/src/test/util.sh: line 287: 73810 Aborted                 (core dumped) _RR_TRACE_DIR="$workdir" test-monitor $TIMEOUT replay.err $RR_EXE $GLOBAL_OPTIONS replay -a $replayflags > replay.out 2> replay.err
Test 'pkeys_32' FAILED: : error during replay:
--------------------------------------------------
[ERROR src/Registers.cc:295:maybe_print_reg_mismatch()] ecx 0xffd37cec != 0x1000 (replaying vs. recorded)
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackEv+0x60)[0x55823daee2c5]
rr(_ZN2rr15notifying_abortEv+0x16)[0x55823daee21e]
rr(_ZN2rr25NewlineTerminatingOstreamD1Ev+0x65)[0x55823d913ad9]
rr(+0x504d02)[0x55823da14d02]
rr(_ZN2rr9Registers22compare_registers_coreINS_7X86ArchEEEbPKcRKS0_S4_S6_NS_16MismatchBehaviorE+0x148)[0x55823da19b44]
rr(_ZN2rr9Registers22compare_registers_archINS_7X86ArchEEEbPKcRKS0_S4_S6_NS_16MismatchBehaviorE+0x3e)[0x55823da14ebe]
rr(_ZN2rr9Registers31compare_register_files_internalEPKcRKS0_S2_S4_NS_16MismatchBehaviorE+0x11c)[0x55823da150fe]
rr(_ZN2rr9Registers22compare_register_filesEPNS_10ReplayTaskEPKcRKS0_S4_S6_NS_16MismatchBehaviorE+0x5e)[0x55823da151f6]
rr(_ZN2rr10ReplayTask13validate_regsEj+0x22e)[0x55823da3e272]
rr(+0x511b58)[0x55823da21b58]
rr(_ZN2rr13ReplaySession13enter_syscallEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0x51a)[0x55823da2208e]
rr(_ZN2rr13ReplaySession18try_one_trace_stepEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0x127)[0x55823da27249]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x1d7)[0x55823da28afb]
rr(_ZN2rr13ReplaySession11replay_stepENS_10RunCommandE+0x4f)[0x55823da1dce7]
rr(+0x50c17b)[0x55823da1c17b]
rr(+0x50c99f)[0x55823da1c99f]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x41f)[0x55823da1d921]
rr(main+0x278)[0x55823db0cd54]
/lib/x86_64-linux-gnu/libc.so.6(+0x29d90)[0x7fc5d12b6d90]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x80)[0x7fc5d12b6e40]
rr(_start+0x25)[0x55823d81a735]
=== End rr backtrace
process 73811 sent SIGURG
====== /proc/73811/status
Name:   rr
Umask:  0002
State:  S (sleeping)
Tgid:   73811
Ngid:   0
Pid:    73811
PPid:   73810
TracerPid:  0
Uid:    1000    1000    1000    1000
Gid:    1000    1000    1000    1000
FDSize: 64
Groups: 4 20 24 27 30 44 46 122 133 134 136 137 140 998 1000 
NStgid: 73811
NSpid:  73811
NSpgid: 73811
NSsid:  3710389
VmPeak:    16908 kB
VmSize:    16908 kB
VmLck:         0 kB
VmPin:         0 kB
VmHWM:      9844 kB
VmRSS:      9584 kB
RssAnon:         936 kB
RssFile:        8648 kB
RssShmem:          0 kB
VmData:     1004 kB
VmStk:       132 kB
VmExe:      3292 kB
VmLib:      4056 kB
VmPTE:        68 kB
VmSwap:        0 kB
HugetlbPages:          0 kB
CoreDumping:    0
THP_enabled:    1
Threads:    1
SigQ:   1/126852
SigPnd: 0000000000000000
ShdPnd: 0000000000000000
SigBlk: 0000000000000000
SigIgn: 0000000180000000
SigCgt: 0000000000002000
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:   0100
Cpus_allowed_list:  8
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:    245
nonvoluntary_ctxt_switches: 1
====== /proc/73811/stack
====== /proc/73812/status
Name:   rr:pkeys_32-Jon
Umask:  0002
State:  t (tracing stop)
Tgid:   73812
Ngid:   0
Pid:    73812
PPid:   73811
TracerPid:  73811
Uid:    1000    1000    1000    1000
Gid:    1000    1000    1000    1000
FDSize: 1024
Groups: 4 20 24 27 30 44 46 122 133 134 136 137 140 998 1000 
NStgid: 73812
NSpid:  73812
NSpgid: 73812
NSsid:  73812
VmPeak:     5824 kB
VmSize:     5824 kB
VmLck:         0 kB
VmPin:         0 kB
VmHWM:      1060 kB
VmRSS:      1060 kB
RssAnon:         272 kB
RssFile:         788 kB
RssShmem:          0 kB
VmData:     2272 kB
VmStk:         0 kB
VmExe:         4 kB
VmLib:      1744 kB
VmPTE:        44 kB
VmSwap:        0 kB
HugetlbPages:          0 kB
CoreDumping:    0
THP_enabled:    1
Threads:    1
SigQ:   1/126852
SigPnd: 0000000000000000
ShdPnd: 0000000000000000
SigBlk: 0000000000000000
SigIgn: 0000000180010000
SigCgt: 0000000000000000
CapInh: 0000000000000000
CapPrm: 0000000000000000
CapEff: 0000000000000000
CapBnd: 000001ffffffffff
CapAmb: 0000000000000000
NoNewPrivs: 1
Seccomp:    0
Seccomp_filters:    0
Speculation_Store_Bypass:   thread vulnerable
SpeculationIndirectBranch:  conditional enabled
Cpus_allowed:   0100
Cpus_allowed_list:  8
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:    244
nonvoluntary_ctxt_switches: 0
====== /proc/73812/stack
====== gdb -p 73811 -ex 'set confirm off' -ex 'set height 0' -ex 'thread apply all bt' -ex q </dev/null 2>&1
GNU gdb (Ubuntu 12.0.90-0ubuntu1) 12.0.90
Copyright (C) 2022 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-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".
GEF for linux ready, type `gef' to start, `gef config' to configure
95 commands loaded for GDB 12.0.90 using Python engine 3.10
[*] 1 command could not be loaded, run `gef missing` to know why.
Attaching to process 73811
Could not attach to process.  If your uid matches the uid of the target
process, check the setting of /proc/sys/kernel/yama/ptrace_scope, or try
again as the root user.  For more details, see /etc/sysctl.d/10-ptrace.conf
ptrace: Inappropriate ioctl for device.
--------------------------------------------------
replay.out:
--------------------------------------------------
--------------------------------------------------
Test pkeys_32 failed, leaving behind /tmp/rr-test-pkeys_32-JonopkvLO
To replay the failed test, run
  _RR_TRACE_DIR=/tmp/rr-test-pkeys_32-JonopkvLO rr replay
<end of output>
Test time =   1.13 sec
----------------------------------------------------------
Test Fail Reason:
Error regular expression found in output. Regex=[FAILED]
"x86/pkeys-32" end time: Sep 26 13:50 CEST
"x86/pkeys-32" time elapsed: 00:00:01
----------------------------------------------------------

1881/2841 Testing: x86/pkeys-32-no-syscallbuf
1881/2841 Test: x86/pkeys-32-no-syscallbuf
Command: "/usr/bin/bash" "source_dir/src/test/basic_test.run" "pkeys_32" "-n" "bin_dir" "120"
Directory: /home/russ/work/rr/obj
"x86/pkeys-32-no-syscallbuf" start time: Sep 26 13:50 CEST
Output:
----------------------------------------------------------
source_dir/src/test/util.sh: line 287: 73863 Aborted                 (core dumped) _RR_TRACE_DIR="$workdir" test-monitor $TIMEOUT replay.err $RR_EXE $GLOBAL_OPTIONS replay -a $replayflags > replay.out 2> replay.err
Test 'pkeys_32' FAILED: : error during replay:
--------------------------------------------------
[ERROR src/Registers.cc:295:maybe_print_reg_mismatch()] ecx 0xffd491dc != 0x1000 (replaying vs. recorded)
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackEv+0x60)[0x55658a30f2c5]
rr(_ZN2rr15notifying_abortEv+0x16)[0x55658a30f21e]
rr(_ZN2rr25NewlineTerminatingOstreamD1Ev+0x65)[0x55658a134ad9]
rr(+0x504d02)[0x55658a235d02]
rr(_ZN2rr9Registers22compare_registers_coreINS_7X86ArchEEEbPKcRKS0_S4_S6_NS_16MismatchBehaviorE+0x148)[0x55658a23ab44]
rr(_ZN2rr9Registers22compare_registers_archINS_7X86ArchEEEbPKcRKS0_S4_S6_NS_16MismatchBehaviorE+0x3e)[0x55658a235ebe]
rr(_ZN2rr9Registers31compare_register_files_internalEPKcRKS0_S2_S4_NS_16MismatchBehaviorE+0x11c)[0x55658a2360fe]
rr(_ZN2rr9Registers22compare_register_filesEPNS_10ReplayTaskEPKcRKS0_S4_S6_NS_16MismatchBehaviorE+0x5e)[0x55658a2361f6]
rr(_ZN2rr10ReplayTask13validate_regsEj+0x22e)[0x55658a25f272]
rr(+0x511b58)[0x55658a242b58]
rr(_ZN2rr13ReplaySession13enter_syscallEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0x51a)[0x55658a24308e]
rr(_ZN2rr13ReplaySession18try_one_trace_stepEPNS_10ReplayTaskERKNS0_15StepConstraintsE+0x127)[0x55658a248249]
rr(_ZN2rr13ReplaySession11replay_stepERKNS0_15StepConstraintsE+0x1d7)[0x55658a249afb]
rr(_ZN2rr13ReplaySession11replay_stepENS_10RunCommandE+0x4f)[0x55658a23ece7]
rr(+0x50c17b)[0x55658a23d17b]
rr(+0x50c99f)[0x55658a23d99f]
rr(_ZN2rr13ReplayCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x41f)[0x55658a23e921]
rr(main+0x278)[0x55658a32dd54]
/lib/x86_64-linux-gnu/libc.so.6(+0x29d90)[0x7f28abefbd90]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x80)[0x7f28abefbe40]
rr(_start+0x25)[0x55658a03b735]
=== End rr backtrace
process 73864 sent SIGURG
====== /proc/73864/status
Name:   rr
Umask:  0002
State:  S (sleeping)
Tgid:   73864
Ngid:   0
Pid:    73864
PPid:   73863
TracerPid:  0
Uid:    1000    1000    1000    1000
Gid:    1000    1000    1000    1000
FDSize: 64
Groups: 4 20 24 27 30 44 46 122 133 134 136 137 140 998 1000 
NStgid: 73864
NSpid:  73864
NSpgid: 73864
NSsid:  3710389
VmPeak:    16292 kB
VmSize:    15824 kB
VmLck:         0 kB
VmPin:         0 kB
VmHWM:      9900 kB
VmRSS:      9608 kB
RssAnon:         876 kB
RssFile:        8732 kB
RssShmem:          0 kB
VmData:      944 kB
VmStk:       132 kB
VmExe:      3292 kB
VmLib:      4056 kB
VmPTE:        72 kB
VmSwap:        0 kB
HugetlbPages:          0 kB
CoreDumping:    0
THP_enabled:    1
Threads:    1
SigQ:   1/126852
SigPnd: 0000000000000000
ShdPnd: 0000000000000000
SigBlk: 0000000000000000
SigIgn: 0000000180000000
SigCgt: 0000000000002000
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:   0008
Cpus_allowed_list:  3
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:    234
nonvoluntary_ctxt_switches: 1
====== /proc/73864/stack
====== /proc/73865/status
Name:   rr:pkeys_32-T6Y
Umask:  0002
State:  t (tracing stop)
Tgid:   73865
Ngid:   0
Pid:    73865
PPid:   73864
TracerPid:  73864
Uid:    1000    1000    1000    1000
Gid:    1000    1000    1000    1000
FDSize: 1024
Groups: 4 20 24 27 30 44 46 122 133 134 136 137 140 998 1000 
NStgid: 73865
NSpid:  73865
NSpgid: 73865
NSsid:  73865
VmPeak:     4968 kB
VmSize:     4796 kB
VmLck:         0 kB
VmPin:         0 kB
VmHWM:      1044 kB
VmRSS:      1044 kB
RssAnon:         264 kB
RssFile:         780 kB
RssShmem:          0 kB
VmData:     2272 kB
VmStk:         0 kB
VmExe:         4 kB
VmLib:      1740 kB
VmPTE:        36 kB
VmSwap:        0 kB
HugetlbPages:          0 kB
CoreDumping:    0
THP_enabled:    1
Threads:    1
SigQ:   1/126852
SigPnd: 0000000000000000
ShdPnd: 0000000000000000
SigBlk: 0000000000000000
SigIgn: 0000000180010000
SigCgt: 0000000000000000
CapInh: 0000000000000000
CapPrm: 0000000000000000
CapEff: 0000000000000000
CapBnd: 000001ffffffffff
CapAmb: 0000000000000000
NoNewPrivs: 1
Seccomp:    0
Seccomp_filters:    0
Speculation_Store_Bypass:   thread vulnerable
SpeculationIndirectBranch:  conditional enabled
Cpus_allowed:   0008
Cpus_allowed_list:  3
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:    233
nonvoluntary_ctxt_switches: 0
====== /proc/73865/stack
====== gdb -p 73864 -ex 'set confirm off' -ex 'set height 0' -ex 'thread apply all bt' -ex q </dev/null 2>&1
GNU gdb (Ubuntu 12.0.90-0ubuntu1) 12.0.90
Copyright (C) 2022 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-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".
GEF for linux ready, type `gef' to start, `gef config' to configure
95 commands loaded for GDB 12.0.90 using Python engine 3.10
[*] 1 command could not be loaded, run `gef missing` to know why.
Attaching to process 73864
Could not attach to process.  If your uid matches the uid of the target
process, check the setting of /proc/sys/kernel/yama/ptrace_scope, or try
again as the root user.  For more details, see /etc/sysctl.d/10-ptrace.conf
ptrace: Inappropriate ioctl for device.
--------------------------------------------------
replay.out:
--------------------------------------------------
--------------------------------------------------
Test pkeys_32 failed, leaving behind /tmp/rr-test-pkeys_32-T6YoRBlLA
To replay the failed test, run
  _RR_TRACE_DIR=/tmp/rr-test-pkeys_32-T6YoRBlLA rr replay
<end of output>
Test time =   1.13 sec
----------------------------------------------------------
Test Fail Reason:
Error regular expression found in output. Regex=[FAILED]
"x86/pkeys-32-no-syscallbuf" end time: Sep 26 13:50 CEST
"x86/pkeys-32-no-syscallbuf" time elapsed: 00:00:01
----------------------------------------------------------
GitMensch commented 2 years ago

Thanks for this additional info, would you mind adding uname -a and more important cat /proc/cpuinfo?

khuey commented 2 years ago

The pkeys test failure is a known kernel bug.

russkel commented 2 years ago

Thanks for this additional info, would you mind adding uname -a and more important cat /proc/cpuinfo?

Sure:

↳ uname -a
Linux kalesmoothie 5.15.0-48-generic #54-Ubuntu SMP Fri Aug 26 13:26:29 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux

processor   : 0
vendor_id   : GenuineIntel
cpu family  : 6
model       : 141
model name  : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
stepping    : 1
microcode   : 0x40
cpu MHz     : 2300.000
cache size  : 24576 KB
physical id : 0
siblings    : 16
core id     : 0
cpu cores   : 8
apicid      : 0
initial apicid  : 0
fpu     : yes
fpu_exception   : yes
cpuid level : 27
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l2 invpcid_single cdp_l2 ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves split_lock_detect dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid movdiri movdir64b fsrm avx512_vp2intersect md_clear flush_l1d arch_capabilities
vmx flags   : vnmi preemption_timer posted_intr invvpid ept_x_only ept_ad ept_1gb flexpriority apicv tsc_offset vtpr mtf vapic ept vpid unrestricted_guest vapic_reg vid ple pml ept_mode_based_exec tsc_scaling
bugs        : spectre_v1 spectre_v2 spec_store_bypass swapgs
bogomips    : 4608.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:

processor   : 1
vendor_id   : GenuineIntel
cpu family  : 6
model       : 141
model name  : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
stepping    : 1
microcode   : 0x40
cpu MHz     : 2300.000
cache size  : 24576 KB
physical id : 0
siblings    : 16
core id     : 1
cpu cores   : 8
apicid      : 2
initial apicid  : 2
fpu     : yes
fpu_exception   : yes
cpuid level : 27
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l2 invpcid_single cdp_l2 ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves split_lock_detect dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid movdiri movdir64b fsrm avx512_vp2intersect md_clear flush_l1d arch_capabilities
vmx flags   : vnmi preemption_timer posted_intr invvpid ept_x_only ept_ad ept_1gb flexpriority apicv tsc_offset vtpr mtf vapic ept vpid unrestricted_guest vapic_reg vid ple pml ept_mode_based_exec tsc_scaling
bugs        : spectre_v1 spectre_v2 spec_store_bypass swapgs
bogomips    : 4608.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:

processor   : 2
vendor_id   : GenuineIntel
cpu family  : 6
model       : 141
model name  : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
stepping    : 1
microcode   : 0x40
cpu MHz     : 2300.000
cache size  : 24576 KB
physical id : 0
siblings    : 16
core id     : 2
cpu cores   : 8
apicid      : 4
initial apicid  : 4
fpu     : yes
fpu_exception   : yes
cpuid level : 27
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l2 invpcid_single cdp_l2 ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves split_lock_detect dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid movdiri movdir64b fsrm avx512_vp2intersect md_clear flush_l1d arch_capabilities
vmx flags   : vnmi preemption_timer posted_intr invvpid ept_x_only ept_ad ept_1gb flexpriority apicv tsc_offset vtpr mtf vapic ept vpid unrestricted_guest vapic_reg vid ple pml ept_mode_based_exec tsc_scaling
bugs        : spectre_v1 spectre_v2 spec_store_bypass swapgs
bogomips    : 4608.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:

processor   : 3
vendor_id   : GenuineIntel
cpu family  : 6
model       : 141
model name  : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
stepping    : 1
microcode   : 0x40
cpu MHz     : 2300.000
cache size  : 24576 KB
physical id : 0
siblings    : 16
core id     : 3
cpu cores   : 8
apicid      : 6
initial apicid  : 6
fpu     : yes
fpu_exception   : yes
cpuid level : 27
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l2 invpcid_single cdp_l2 ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves split_lock_detect dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid movdiri movdir64b fsrm avx512_vp2intersect md_clear flush_l1d arch_capabilities
vmx flags   : vnmi preemption_timer posted_intr invvpid ept_x_only ept_ad ept_1gb flexpriority apicv tsc_offset vtpr mtf vapic ept vpid unrestricted_guest vapic_reg vid ple pml ept_mode_based_exec tsc_scaling
bugs        : spectre_v1 spectre_v2 spec_store_bypass swapgs
bogomips    : 4608.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:

processor   : 4
vendor_id   : GenuineIntel
cpu family  : 6
model       : 141
model name  : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
stepping    : 1
microcode   : 0x40
cpu MHz     : 2300.000
cache size  : 24576 KB
physical id : 0
siblings    : 16
core id     : 4
cpu cores   : 8
apicid      : 8
initial apicid  : 8
fpu     : yes
fpu_exception   : yes
cpuid level : 27
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l2 invpcid_single cdp_l2 ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves split_lock_detect dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid movdiri movdir64b fsrm avx512_vp2intersect md_clear flush_l1d arch_capabilities
vmx flags   : vnmi preemption_timer posted_intr invvpid ept_x_only ept_ad ept_1gb flexpriority apicv tsc_offset vtpr mtf vapic ept vpid unrestricted_guest vapic_reg vid ple pml ept_mode_based_exec tsc_scaling
bugs        : spectre_v1 spectre_v2 spec_store_bypass swapgs
bogomips    : 4608.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:

processor   : 5
vendor_id   : GenuineIntel
cpu family  : 6
model       : 141
model name  : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
stepping    : 1
microcode   : 0x40
cpu MHz     : 2300.000
cache size  : 24576 KB
physical id : 0
siblings    : 16
core id     : 5
cpu cores   : 8
apicid      : 10
initial apicid  : 10
fpu     : yes
fpu_exception   : yes
cpuid level : 27
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l2 invpcid_single cdp_l2 ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves split_lock_detect dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid movdiri movdir64b fsrm avx512_vp2intersect md_clear flush_l1d arch_capabilities
vmx flags   : vnmi preemption_timer posted_intr invvpid ept_x_only ept_ad ept_1gb flexpriority apicv tsc_offset vtpr mtf vapic ept vpid unrestricted_guest vapic_reg vid ple pml ept_mode_based_exec tsc_scaling
bugs        : spectre_v1 spectre_v2 spec_store_bypass swapgs
bogomips    : 4608.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:

processor   : 6
vendor_id   : GenuineIntel
cpu family  : 6
model       : 141
model name  : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
stepping    : 1
microcode   : 0x40
cpu MHz     : 2300.000
cache size  : 24576 KB
physical id : 0
siblings    : 16
core id     : 6
cpu cores   : 8
apicid      : 12
initial apicid  : 12
fpu     : yes
fpu_exception   : yes
cpuid level : 27
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l2 invpcid_single cdp_l2 ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves split_lock_detect dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid movdiri movdir64b fsrm avx512_vp2intersect md_clear flush_l1d arch_capabilities
vmx flags   : vnmi preemption_timer posted_intr invvpid ept_x_only ept_ad ept_1gb flexpriority apicv tsc_offset vtpr mtf vapic ept vpid unrestricted_guest vapic_reg vid ple pml ept_mode_based_exec tsc_scaling
bugs        : spectre_v1 spectre_v2 spec_store_bypass swapgs
bogomips    : 4608.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:

processor   : 7
vendor_id   : GenuineIntel
cpu family  : 6
model       : 141
model name  : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
stepping    : 1
microcode   : 0x40
cpu MHz     : 2300.000
cache size  : 24576 KB
physical id : 0
siblings    : 16
core id     : 7
cpu cores   : 8
apicid      : 14
initial apicid  : 14
fpu     : yes
fpu_exception   : yes
cpuid level : 27
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l2 invpcid_single cdp_l2 ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves split_lock_detect dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid movdiri movdir64b fsrm avx512_vp2intersect md_clear flush_l1d arch_capabilities
vmx flags   : vnmi preemption_timer posted_intr invvpid ept_x_only ept_ad ept_1gb flexpriority apicv tsc_offset vtpr mtf vapic ept vpid unrestricted_guest vapic_reg vid ple pml ept_mode_based_exec tsc_scaling
bugs        : spectre_v1 spectre_v2 spec_store_bypass swapgs
bogomips    : 4608.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:

processor   : 8
vendor_id   : GenuineIntel
cpu family  : 6
model       : 141
model name  : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
stepping    : 1
microcode   : 0x40
cpu MHz     : 2300.000
cache size  : 24576 KB
physical id : 0
siblings    : 16
core id     : 0
cpu cores   : 8
apicid      : 1
initial apicid  : 1
fpu     : yes
fpu_exception   : yes
cpuid level : 27
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l2 invpcid_single cdp_l2 ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves split_lock_detect dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid movdiri movdir64b fsrm avx512_vp2intersect md_clear flush_l1d arch_capabilities
vmx flags   : vnmi preemption_timer posted_intr invvpid ept_x_only ept_ad ept_1gb flexpriority apicv tsc_offset vtpr mtf vapic ept vpid unrestricted_guest vapic_reg vid ple pml ept_mode_based_exec tsc_scaling
bugs        : spectre_v1 spectre_v2 spec_store_bypass swapgs
bogomips    : 4608.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:

processor   : 9
vendor_id   : GenuineIntel
cpu family  : 6
model       : 141
model name  : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
stepping    : 1
microcode   : 0x40
cpu MHz     : 2300.000
cache size  : 24576 KB
physical id : 0
siblings    : 16
core id     : 1
cpu cores   : 8
apicid      : 3
initial apicid  : 3
fpu     : yes
fpu_exception   : yes
cpuid level : 27
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l2 invpcid_single cdp_l2 ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves split_lock_detect dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid movdiri movdir64b fsrm avx512_vp2intersect md_clear flush_l1d arch_capabilities
vmx flags   : vnmi preemption_timer posted_intr invvpid ept_x_only ept_ad ept_1gb flexpriority apicv tsc_offset vtpr mtf vapic ept vpid unrestricted_guest vapic_reg vid ple pml ept_mode_based_exec tsc_scaling
bugs        : spectre_v1 spectre_v2 spec_store_bypass swapgs
bogomips    : 4608.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:

processor   : 10
vendor_id   : GenuineIntel
cpu family  : 6
model       : 141
model name  : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
stepping    : 1
microcode   : 0x40
cpu MHz     : 2300.000
cache size  : 24576 KB
physical id : 0
siblings    : 16
core id     : 2
cpu cores   : 8
apicid      : 5
initial apicid  : 5
fpu     : yes
fpu_exception   : yes
cpuid level : 27
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l2 invpcid_single cdp_l2 ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves split_lock_detect dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid movdiri movdir64b fsrm avx512_vp2intersect md_clear flush_l1d arch_capabilities
vmx flags   : vnmi preemption_timer posted_intr invvpid ept_x_only ept_ad ept_1gb flexpriority apicv tsc_offset vtpr mtf vapic ept vpid unrestricted_guest vapic_reg vid ple pml ept_mode_based_exec tsc_scaling
bugs        : spectre_v1 spectre_v2 spec_store_bypass swapgs
bogomips    : 4608.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:

processor   : 11
vendor_id   : GenuineIntel
cpu family  : 6
model       : 141
model name  : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
stepping    : 1
microcode   : 0x40
cpu MHz     : 2300.000
cache size  : 24576 KB
physical id : 0
siblings    : 16
core id     : 3
cpu cores   : 8
apicid      : 7
initial apicid  : 7
fpu     : yes
fpu_exception   : yes
cpuid level : 27
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l2 invpcid_single cdp_l2 ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves split_lock_detect dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid movdiri movdir64b fsrm avx512_vp2intersect md_clear flush_l1d arch_capabilities
vmx flags   : vnmi preemption_timer posted_intr invvpid ept_x_only ept_ad ept_1gb flexpriority apicv tsc_offset vtpr mtf vapic ept vpid unrestricted_guest vapic_reg vid ple pml ept_mode_based_exec tsc_scaling
bugs        : spectre_v1 spectre_v2 spec_store_bypass swapgs
bogomips    : 4608.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:

processor   : 12
vendor_id   : GenuineIntel
cpu family  : 6
model       : 141
model name  : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
stepping    : 1
microcode   : 0x40
cpu MHz     : 2300.000
cache size  : 24576 KB
physical id : 0
siblings    : 16
core id     : 4
cpu cores   : 8
apicid      : 9
initial apicid  : 9
fpu     : yes
fpu_exception   : yes
cpuid level : 27
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l2 invpcid_single cdp_l2 ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves split_lock_detect dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid movdiri movdir64b fsrm avx512_vp2intersect md_clear flush_l1d arch_capabilities
vmx flags   : vnmi preemption_timer posted_intr invvpid ept_x_only ept_ad ept_1gb flexpriority apicv tsc_offset vtpr mtf vapic ept vpid unrestricted_guest vapic_reg vid ple pml ept_mode_based_exec tsc_scaling
bugs        : spectre_v1 spectre_v2 spec_store_bypass swapgs
bogomips    : 4608.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:

processor   : 13
vendor_id   : GenuineIntel
cpu family  : 6
model       : 141
model name  : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
stepping    : 1
microcode   : 0x40
cpu MHz     : 3903.795
cache size  : 24576 KB
physical id : 0
siblings    : 16
core id     : 5
cpu cores   : 8
apicid      : 11
initial apicid  : 11
fpu     : yes
fpu_exception   : yes
cpuid level : 27
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l2 invpcid_single cdp_l2 ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves split_lock_detect dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid movdiri movdir64b fsrm avx512_vp2intersect md_clear flush_l1d arch_capabilities
vmx flags   : vnmi preemption_timer posted_intr invvpid ept_x_only ept_ad ept_1gb flexpriority apicv tsc_offset vtpr mtf vapic ept vpid unrestricted_guest vapic_reg vid ple pml ept_mode_based_exec tsc_scaling
bugs        : spectre_v1 spectre_v2 spec_store_bypass swapgs
bogomips    : 4608.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:

processor   : 14
vendor_id   : GenuineIntel
cpu family  : 6
model       : 141
model name  : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
stepping    : 1
microcode   : 0x40
cpu MHz     : 2300.000
cache size  : 24576 KB
physical id : 0
siblings    : 16
core id     : 6
cpu cores   : 8
apicid      : 13
initial apicid  : 13
fpu     : yes
fpu_exception   : yes
cpuid level : 27
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l2 invpcid_single cdp_l2 ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves split_lock_detect dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid movdiri movdir64b fsrm avx512_vp2intersect md_clear flush_l1d arch_capabilities
vmx flags   : vnmi preemption_timer posted_intr invvpid ept_x_only ept_ad ept_1gb flexpriority apicv tsc_offset vtpr mtf vapic ept vpid unrestricted_guest vapic_reg vid ple pml ept_mode_based_exec tsc_scaling
bugs        : spectre_v1 spectre_v2 spec_store_bypass swapgs
bogomips    : 4608.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:

processor   : 15
vendor_id   : GenuineIntel
cpu family  : 6
model       : 141
model name  : 11th Gen Intel(R) Core(TM) i7-11800H @ 2.30GHz
stepping    : 1
microcode   : 0x40
cpu MHz     : 2300.000
cache size  : 24576 KB
physical id : 0
siblings    : 16
core id     : 7
cpu cores   : 8
apicid      : 15
initial apicid  : 15
fpu     : yes
fpu_exception   : yes
cpuid level : 27
wp      : yes
flags       : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l2 invpcid_single cdp_l2 ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves split_lock_detect dtherm ida arat pln pts hwp hwp_notify hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid movdiri movdir64b fsrm avx512_vp2intersect md_clear flush_l1d arch_capabilities
vmx flags   : vnmi preemption_timer posted_intr invvpid ept_x_only ept_ad ept_1gb flexpriority apicv tsc_offset vtpr mtf vapic ept vpid unrestricted_guest vapic_reg vid ple pml ept_mode_based_exec tsc_scaling
bugs        : spectre_v1 spectre_v2 spec_store_bypass swapgs
bogomips    : 4608.00
clflush size    : 64
cache_alignment : 64
address sizes   : 39 bits physical, 48 bits virtual
power management:
GitMensch commented 2 years ago

I guess that's possibly about the specific processor, not about Ubuntu or that specific kernel.

Just for reference: the pkeys test failure (happening at replay time) seems to be #3032, but that is a different issue than your "futex facility error" / segfault (happening at recording time). There was something similar (but at replay time) to your issue that resolved as "libc/libpthread version mismatch" in #2767.

russkel commented 2 years ago

Yes, that makes sense, I will remove ubuntu from the title.

That aside, the issue was introduced at some point since 5.5.0 because I have reverted to it to get debugging done.

khuey commented 2 years ago

So, my understanding of the current situation is:

  1. rr recording your workload with rr 5.6 fails with this futex unexpected error thing
  2. rr recording the same workload with rr 5.5 works fine
  3. 1 applies whether you use the packaged rr 5.6 or whether you build it from source
  4. When you build rr 5.6 from source all the tests pass (modulo the pkeys issue which is a known kernel bug in 5.15 and later kernels).

Is that accurate?

If so, one question I have is whether your workload is using a different libc than rr itself? It would help if we could reproduce this failure on our machines somehow.

russkel commented 2 years ago

@khuey this is correct.

Regarding the libc version. The workload has been compiled recently and with the system version of libc, same with rr.

↳ ldd install/is-core/bin/integration-service 
    linux-vdso.so.1 (0x00007ffd7ef76000)
    libis-core.so.3.1 => /home/russ/work/is-workspace/install/is-core/lib/libis-core.so.3.1 (0x00007f848421e000)
    libstdc++.so.6 => /lib/x86_64-linux-gnu/libstdc++.so.6 (0x00007f8483fc9000)
    libgcc_s.so.1 => /lib/x86_64-linux-gnu/libgcc_s.so.1 (0x00007f8483fa9000)
    libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007f8483d7f000)
    libyaml-cpp.so.0.7 => /lib/x86_64-linux-gnu/libyaml-cpp.so.0.7 (0x00007f8483d40000)
    libboost_program_options.so.1.74.0 => /lib/x86_64-linux-gnu/libboost_program_options.so.1.74.0 (0x00007f8483cfb000)
    /lib64/ld-linux-x86-64.so.2 (0x00007f84843ec000)
    libm.so.6 => /lib/x86_64-linux-gnu/libm.so.6 (0x00007f8483c14000)
↳ ldd ~/work/rr/obj/bin/rr
    linux-vdso.so.1 (0x00007ffc24724000)
    libz.so.1 => /lib/x86_64-linux-gnu/libz.so.1 (0x00007fe10c001000)
    libcapnp-0.8.0.so => /lib/x86_64-linux-gnu/libcapnp-0.8.0.so (0x00007fe10bf84000)
    libkj-0.8.0.so => /lib/x86_64-linux-gnu/libkj-0.8.0.so (0x00007fe10bf16000)
    libstdc++.so.6 => /lib/x86_64-linux-gnu/libstdc++.so.6 (0x00007fe10bcea000)
    libm.so.6 => /lib/x86_64-linux-gnu/libm.so.6 (0x00007fe10bc03000)
    libgcc_s.so.1 => /lib/x86_64-linux-gnu/libgcc_s.so.1 (0x00007fe10bbe3000)
    libc.so.6 => /lib/x86_64-linux-gnu/libc.so.6 (0x00007fe10b9bb000)
    /lib64/ld-linux-x86-64.so.2 (0x00007fe10c82e000)
khuey commented 2 years ago

Ok. Is this workload open source?

russkel commented 2 years ago

Yes, all open source. Unfortunately getting it setup is a bit complicated because of how many levels deep it goes. Are you looking for the source code or running it yourself? Compiling yourself involves setting up colcon, installing ros2 debian repos, cloning my patched repos, and compiling Integration services, xtypes and the ros2-sh.

Integration Services dynamically loads shared libs to add functionality. Looking at the stack trace here https://github.com/rr-debugger/rr/issues/3358#issuecomment-1208728476 the futex error is occurring within rclcpp: https://github.com/ros2/rclcpp/blob/humble/rclcpp/src/rclcpp/signal_handler.cpp#L325. rclcpp is linked by ROS2-SH.

So it goes integration-service --> dynamically loads ros2-sh lib --> linked to rclcpp shared lib

https://github.com/eProsima/Integration-Service https://github.com/eProsima/ROS2-SH

dr-m commented 1 year ago

We got a trace of this while testing https://github.com/MariaDB/server/ using rr 5.6.0 on Ubuntu, kernel 5.15.0-52-generic, glibc 2.35-0ubuntu3.1, on AMD64. At the time of the fatal signal, the crashing thread was doing this:

#0  __pthread_kill_implementation (no_tid=0, signo=6, threadid=75798938871360) at ./nptl/pthread_kill.c:44
#1  __pthread_kill_internal (signo=6, threadid=75798938871360) at ./nptl/pthread_kill.c:78
#2  __GI___pthread_kill (threadid=75798938871360, signo=signo@entry=6) at ./nptl/pthread_kill.c:89
#3  0x00000ec71e440476 in __GI_raise (sig=sig@entry=6) at ../sysdeps/posix/raise.c:26
#4  0x00000ec71e4267f3 in __GI_abort () at ./stdlib/abort.c:79
#5  0x00000ec71e48745c in __libc_message (action=do_abort, fmt=0xec71e5d97b1 "%s", fmt=0xec71e5d97b1 "%s", action=do_abort) at ../sysdeps/posix/libc_fatal.c:155
#6  0x00000ec71e487770 in __GI___libc_fatal (message=message@entry=0xec71e5dbd28 "The futex facility returned an unexpected error code.\n") at ../sysdeps/posix/libc_fatal.c:164
#7  0x00000ec71e48f12e in futex_fatal_error () at ../sysdeps/nptl/futex-internal.h:87
#8  __futex_abstimed_wait_common (cancel=true, private=1356028368, abstime=0xdb, clockid=0, expected=0, futex_word=0x561ce2826b68) at ./nptl/futex-internal.c:119
#9  __GI___futex_abstimed_wait_cancelable64 (futex_word=futex_word@entry=0x561ce2826b68, expected=expected@entry=0, clockid=clockid@entry=1, abstime=abstime@entry=0x44f050d35b00, private=private@entry=0) at ./nptl/futex-internal.c:139
#10 0x00000ec71e49235d in __pthread_cond_wait_common (abstime=0x44f050d35b00, clockid=1, mutex=0x561ce2800bd0, cond=0x561ce2826b40) at ./nptl/pthread_cond_wait.c:503
#11 ___pthread_cond_clockwait64 (abstime=0x44f050d35b00, clockid=1, mutex=0x561ce2800bd0, cond=0x561ce2826b40) at ./nptl/pthread_cond_wait.c:691
#12 ___pthread_cond_clockwait64 (cond=0x561ce2826b40, mutex=0x561ce2800bd0, clockid=1, abstime=0x44f050d35b00) at ./nptl/pthread_cond_wait.c:679
#13 0x0000561ce0666628 in std::__condvar::wait_until (__abs_time=@0x44f050d35b00: {tv_sec = 3020588, tv_nsec = 901155480}, __clock=1, __m=<optimized out>, this=0x44f050d35b38) at /usr/include/c++/11/bits/std_mutex.h:169
#14 std::condition_variable::__wait_until_impl<std::chrono::duration<long, std::ratio<1l, 1000000000l> > > (this=this@entry=0x561ce2826b40, __lock=@0x44f050d35b80: {_M_device = 0x561ce2800bd0, _M_owns = true}, __atime=@0x44f050d35b38: {__d = {__r = 3020588901155480}}) at /usr/include/c++/11/condition_variable:201
#15 0x0000561ce0664f9c in std::condition_variable::wait_until<std::chrono::duration<long, std::ratio<1l, 1000000000l> > > (__atime=@0x44f050d35b38: {__d = {__r = 3020588901155480}}, __lock=@0x44f050d35b80: {_M_device = 0x561ce2800bd0, _M_owns = true}, this=0x561ce2826b40) at /usr/include/c++/11/condition_variable:111
#16 std::condition_variable::wait_for<long, std::ratio<1l, 1000l> > (__rtime=@0x561ce2800bf8: {__r = 60000}, __lock=@0x44f050d35b80: {_M_device = 0x561ce2800bd0, _M_owns = true}, this=0x561ce2826b40) at /usr/include/c++/11/condition_variable:163

I was able to trace it down to the system call level. It looks like after the syscall instruction happened, the code will be patched. I can’t seem to be able to reverse-stepi from the syscall (I would get SIGTRAP in another thread), but setting a breakpoint on the address works:

(rr) break *0xec71e48f195 thread 2
Breakpoint 2 at 0xec71e48f195: file ./nptl/futex-internal.c, line 57.
(rr) reverse-continue
Continuing.

Thread 2 hit Breakpoint 2, 0x00000ec71e48f195 in __futex_abstimed_wait_common64 (private=509690624, cancel=true, abstime=0x44f050d35b00, op=137, expected=0, futex_word=0x561ce2826b68) at ./nptl/futex-internal.c:57
57  ./nptl/futex-internal.c: No such file or directory.
(rr) display/i $pc
1: x/i $pc
=> 0xec71e48f195 <__GI___futex_abstimed_wait_cancelable64+229>: nop
(rr) reverse-continue
Continuing.

Thread 2 hit Breakpoint 2, 0x00000ec71e48f195 in __futex_abstimed_wait_common64 (private=509690624, cancel=true, abstime=0x44f050d35b00, op=137, expected=0, futex_word=0x561ce2826b68) at ./nptl/futex-internal.c:57
57  in ./nptl/futex-internal.c
1: x/i $pc
=> 0xec71e48f195 <__GI___futex_abstimed_wait_cancelable64+229>: syscall 

The relevant part of the function disassembly:

(rr) disassemble
Dump of assembler code for function __GI___futex_abstimed_wait_cancelable64:
   0x00000ec71e48f0b0 <+0>: endbr64 
…
   0x00000ec71e48f16e <+190>:   call   0xec71e48ea70 <__GI___pthread_enable_asynccancel>
   0x00000ec71e48f173 <+195>:   mov    0x18(%rsp),%r10
   0x00000ec71e48f178 <+200>:   xor    %r8d,%r8d
   0x00000ec71e48f17b <+203>:   mov    %r13d,%edx
   0x00000ec71e48f17e <+206>:   mov    %eax,%r12d
   0x00000ec71e48f181 <+209>:   mov    0xc(%rsp),%esi
   0x00000ec71e48f185 <+213>:   mov    0x10(%rsp),%rdi
   0x00000ec71e48f18a <+218>:   mov    $0xffffffff,%r9d
   0x00000ec71e48f190 <+224>:   mov    $0xca,%eax
=> 0x00000ec71e48f195 <+229>:   syscall 
   0x00000ec71e48f197 <+231>:   mov    %r12d,%edi
   0x00000ec71e48f19a <+234>:   mov    %rax,%rbx
   0x00000ec71e48f19d <+237>:   call   0xec71e48eae0 <__GI___pthread_disable_asynccancel>

info reg before and after entering the system call:

(rr) info reg
rax            0xca                202
rbx            0x44f050d35b00      75798938868480
rcx            0x44f050d36640      75798938871360
rdx            0x0                 0
rsi            0x89                137
rdi            0x561ce2826b68      94682059271016
rbp            0x561ce2826b40      0x561ce2826b40
rsp            0x44f050d359e0      0x44f050d359e0
r8             0x0                 0
r9             0xffffffff          4294967295
r10            0x44f050d35b00      75798938868480
r11            0x9                 9
r12            0x0                 0
r13            0x0                 0
r14            0x561ce2826b64      94682059271012
r15            0x561ce2826b68      94682059271016
rip            0xec71e48f195       0xec71e48f195 <__GI___futex_abstimed_wait_cancelable64+229>
eflags         0x246               [ PF ZF IF ]
cs             0x33                51
ss             0x2b                43
ds             0x0                 0
es             0x0                 0
fs             0x0                 0
gs             0x0                 0
(rr) stepi
0x00000ec71e48f196  57  in ./nptl/futex-internal.c
1: x/i $pc
=> 0xec71e48f196 <__GI___futex_abstimed_wait_cancelable64+230>: nop
(rr) info reg
rax            0xdb                219
rbx            0x44f050d35b00      75798938868480
rcx            0xffffffffffffffff  -1
rdx            0x0                 0
rsi            0x89                137
rdi            0x561ce2826b68      94682059271016
rbp            0x561ce2826b40      0x561ce2826b40
rsp            0x44f050d359e0      0x44f050d359e0
r8             0x0                 0
r9             0xffffffff          4294967295
r10            0x44f050d35b00      75798938868480
r11            0x246               582
r12            0x0                 0
r13            0x0                 0
r14            0x561ce2826b64      94682059271012
r15            0x561ce2826b68      94682059271016
rip            0xec71e48f196       0xec71e48f196 <__GI___futex_abstimed_wait_cancelable64+230>
eflags         0x246               [ PF ZF IF ]
cs             0x33                51
ss             0x2b                43
ds             0x0                 0
es             0x0                 0
fs             0x0                 0
gs             0x0                 0

As far as I understand, the system call number is 137 and the return value is 0xdb. I tried to match this code with glibc-2.37 (slightly newer version), but did not quite follow it.

rocallahan commented 1 year ago

Definitely looks like an rr bug but I don't have a clue what the problem could be. We don't do any special processing of FUTEX_WAIT_BITSET.

What does rr dump -b -m -p look like around the syscall that returns 0xdb here?

dr-m commented 1 year ago

I never used rr dump before, but I guess I should pass it an event number range, say, 3538-3540, based on the following:

Thread 2 hit Breakpoint 2, 0x00000ec71e48f195 in __futex_abstimed_wait_common64 (private=509690624, cancel=true, abstime=0x44f050d35b00, op=137, expected=0, futex_word=0x561ce2826b68) at ./nptl/futex-internal.c:57
57  in ./nptl/futex-internal.c
1: x/i $pc
=> 0xec71e48f195 <__GI___futex_abstimed_wait_cancelable64+229>: syscall 
(rr) when
Current event: 3539

Here is the output:

rr dump -b -m -p /data1/results/1694440377/TBR-2014/1_clone/rr/latest-trace 3538-3540
{
  real_time:3020528.901230 global_time:3538, event:`SYSCALL: futex' (state:EXITING_SYSCALL) tid:1840247, ticks:810
rax:0x1 rbx:0x7fb96e2dbfa0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x81 rdi:0x561ce2800bd0 rbp:0xca rsp:0x7fb96e2dbdc0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x561ce2800bd0 r13:0x1 r14:0x561ce2826b64 r15:0xdf8475800 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x44f050d36640 gs_base:0x0
}
{
  real_time:3020528.901299 global_time:3539, event:`SYSCALL: futex' (state:ENTERING_SYSCALL) tid:1840247, ticks:824
rax:0xffffffffffffffda rbx:0x44f050d35b00 rcx:0xffffffffffffffff rdx:0x0 rsi:0x89 rdi:0x561ce2826b68 rbp:0x561ce2826b40 rsp:0x44f050d359e0 r8:0x0 r9:0xffffffff r10:0x44f050d35b00 r11:0x246 r12:0x0 r13:0x0 r14:0x561ce2826b64 r15:0x561ce2826b68 rip:0xec71e48f197 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x44f050d36640 gs_base:0x0
}
{
  real_time:3020528.901325 global_time:3540, event:`SYSCALL: futex' (state:EXITING_SYSCALL) tid:1839759, ticks:10223517
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x189 rdi:0x561ce286b5c8 rbp:0x561ce286b5a0 rsp:0x7ffc32e1bd00 r8:0x0 r9:0xffffffff r10:0x0 r11:0x246 r12:0x0 r13:0x0 r14:0x0 r15:0x561ce286b5c8 rip:0xec71e48f197 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x32881a403e00 gs_base:0x0
}

By the way, this was just a one-time occurrence for us, not too easily repeatable.

rocallahan commented 1 year ago

if you step over that syscall to the exit, then do when, and report the dump range around that event?

dr-m commented 1 year ago
(rr) display/i $pc
1: x/i $pc
=> 0xec71e48f195 <__GI___futex_abstimed_wait_cancelable64+229>: syscall 
(rr) when
Current event: 3539
(rr) si
0x00000ec71e48f196  57  in ./nptl/futex-internal.c
1: x/i $pc
=> 0xec71e48f196 <__GI___futex_abstimed_wait_cancelable64+230>: nop
(rr) when
Current event: 3549

The entire range from before the syscall to after it:

rr dump -b -m -p /data1/results/1694440377/TBR-2014/1_clone/rr/latest-trace 3538-3550
{
  real_time:3020528.901230 global_time:3538, event:`SYSCALL: futex' (state:EXITING_SYSCALL) tid:1840247, ticks:810
rax:0x1 rbx:0x7fb96e2dbfa0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x81 rdi:0x561ce2800bd0 rbp:0xca rsp:0x7fb96e2dbdc0 r8:0x0 r9:0x0 r10:0x0 r11:0x246 r12:0x561ce2800bd0 r13:0x1 r14:0x561ce2826b64 r15:0xdf8475800 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x44f050d36640 gs_base:0x0
}
{
  real_time:3020528.901299 global_time:3539, event:`SYSCALL: futex' (state:ENTERING_SYSCALL) tid:1840247, ticks:824
rax:0xffffffffffffffda rbx:0x44f050d35b00 rcx:0xffffffffffffffff rdx:0x0 rsi:0x89 rdi:0x561ce2826b68 rbp:0x561ce2826b40 rsp:0x44f050d359e0 r8:0x0 r9:0xffffffff r10:0x44f050d35b00 r11:0x246 r12:0x0 r13:0x0 r14:0x561ce2826b64 r15:0x561ce2826b68 rip:0xec71e48f197 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x44f050d36640 gs_base:0x0
}
{
  real_time:3020528.901325 global_time:3540, event:`SYSCALL: futex' (state:EXITING_SYSCALL) tid:1839759, ticks:10223517
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x189 rdi:0x561ce286b5c8 rbp:0x561ce286b5a0 rsp:0x7ffc32e1bd00 r8:0x0 r9:0xffffffff r10:0x0 r11:0x246 r12:0x0 r13:0x0 r14:0x0 r15:0x561ce286b5c8 rip:0xec71e48f197 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x32881a403e00 gs_base:0x0
}
{
  real_time:3020528.901358 global_time:3541, event:`PATCH_SYSCALL' tid:1839759, ticks:10223517
rax:0x0 rbx:0x0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x189 rdi:0x561ce286b5c8 rbp:0x561ce286b5a0 rsp:0x7ffc32e1bd00 r8:0x0 r9:0xffffffff r10:0x0 r11:0x246 r12:0x0 r13:0x0 r14:0x0 r15:0x561ce286b5c8 rip:0xec71e48f197 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x32881a403e00 gs_base:0x0
  { tid:1839759, addr:0xec71e627c7c, length:0x5e }
  { tid:1839759, addr:0xec71e48f190, length:0x7 }
}
{
  real_time:3020528.901421 global_time:3542, event:`SYSCALL: futex' (state:ENTERING_SYSCALL) tid:1839759, ticks:10223619
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x81 rdi:0x561ce286b518 rbp:0xca rsp:0x681ffdc0 r8:0x561ce27e1a00 r9:0x0 r10:0x0 r11:0x246 r12:0x561ce0ae3c20 r13:0xbf r14:0x32881a403e00 r15:0x0 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x32881a403e00 gs_base:0x0
}
{
  real_time:3020528.901450 global_time:3543, event:`SYSCALL: futex' (state:EXITING_SYSCALL) tid:1839759, ticks:10223619
rax:0x0 rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x81 rdi:0x561ce286b518 rbp:0xca rsp:0x681ffdc0 r8:0x561ce27e1a00 r9:0x0 r10:0x0 r11:0x246 r12:0x561ce0ae3c20 r13:0xbf r14:0x32881a403e00 r15:0x0 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x32881a403e00 gs_base:0x0
}
{
  real_time:3020528.903198 global_time:3544, event:`PATCH_SYSCALL' tid:1839759, ticks:10650441
rax:0xca rbx:0x0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x81 rdi:0x561ce1184270 rbp:0x0 rsp:0x7ffc32e1bf30 r8:0x561ce1184248 r9:0x561ce1184268 r10:0x0 r11:0x246 r12:0x0 r13:0x0 r14:0x561ce1184270 r15:0x561ce1184248 rip:0xec71e491343 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xffffffffffffffff fs_base:0x32881a403e00 gs_base:0x0
  { tid:1839759, addr:0xec71e627cda, length:0x5e }
  { tid:1839759, addr:0xec71e491343, length:0x8 }
}
{
  real_time:3020528.903241 global_time:3545, event:`SYSCALL: futex' (state:ENTERING_SYSCALL) tid:1839759, ticks:10650457
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x81 rdi:0x561ce1184270 rbp:0xca rsp:0x681ffdc0 r8:0x561ce1184248 r9:0x561ce1184268 r10:0x0 r11:0x246 r12:0x0 r13:0x0 r14:0x561ce1184270 r15:0x561ce1184248 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x32881a403e00 gs_base:0x0
}
{
  real_time:3020528.903279 global_time:3546, event:`SYSCALL: futex' (state:EXITING_SYSCALL) tid:1839759, ticks:10650457
rax:0x1 rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x1 rsi:0x81 rdi:0x561ce1184270 rbp:0xca rsp:0x681ffdc0 r8:0x561ce1184248 r9:0x561ce1184268 r10:0x0 r11:0x246 r12:0x0 r13:0x0 r14:0x561ce1184270 r15:0x561ce1184248 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x32881a403e00 gs_base:0x0
}
{
  real_time:3020528.903316 global_time:3547, event:`SYSCALL: futex' (state:ENTERING_SYSCALL) tid:1839759, ticks:10650530
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x0 rsi:0x189 rdi:0x561ce11842d0 rbp:0xca rsp:0x681ffdc0 r8:0x0 r9:0xffffffff r10:0x0 r11:0x246 r12:0x0 r13:0x0 r14:0x0 r15:0x561ce11842d0 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x32881a403e00 gs_base:0x0
}
{
  real_time:3020528.903351 global_time:3548, event:`SYSCALL: futex' (state:EXITING_SYSCALL) tid:1840247, ticks:824
rax:0xfffffffffffffdfc rbx:0x44f050d35b00 rcx:0xffffffffffffffff rdx:0x0 rsi:0x89 rdi:0x561ce2826b68 rbp:0x561ce2826b40 rsp:0x44f050d359e0 r8:0x0 r9:0xffffffff r10:0x44f050d35b00 r11:0x246 r12:0x0 r13:0x0 r14:0x561ce2826b64 r15:0x561ce2826b68 rip:0xec71e48f197 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0xca fs_base:0x44f050d36640 gs_base:0x0
}
{
  real_time:3020528.977964 global_time:3549, event:`SYSCALL: writev' (state:ENTERING_SYSCALL) tid:1840247, ticks:831
rax:0xffffffffffffffda rbx:0x44f050d35910 rcx:0xffffffffffffffff rdx:0x1 rsi:0x44f050d35910 rdi:0x2 rbp:0x44f050d359c0 rsp:0x44f050d35910 r8:0x36 r9:0x14 r10:0x44f050d35b00 r11:0x246 r12:0xec71e5dbd28 r13:0x0 r14:0x561ce2826b64 r15:0x561ce2826b68 rip:0xec71e4873ea eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x14 fs_base:0x44f050d36640 gs_base:0x0
}
{
  real_time:3020528.978163 global_time:3550, event:`SYSCALL: writev' (state:EXITING_SYSCALL) tid:1840247, ticks:831
rax:0x36 rbx:0x44f050d35910 rcx:0xffffffffffffffff rdx:0x1 rsi:0x44f050d35910 rdi:0x2 rbp:0x44f050d359c0 rsp:0x44f050d35910 r8:0x36 r9:0x14 r10:0x44f050d35b00 r11:0x246 r12:0xec71e5dbd28 r13:0x0 r14:0x561ce2826b64 r15:0x561ce2826b68 rip:0xec71e4873ea eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x14 fs_base:0x44f050d36640 gs_base:0x0
}
rocallahan commented 1 year ago

Looks like the syscall actually returns ERESTART_RESTARTBLOCK. But the syscall didn't restart, and I guess it should have. I think this is returned by timers that are interrupted, have adjusted their timeout and need to restart.

rocallahan commented 1 year ago

I think we're going to need repeatable steps to reproduce during recording to make progress on this.

dr-m commented 1 year ago

Our tester should return from vacation later this week. I don’t know yet if the trace that we got was a rare unicorn, like many interesting bugs that he catches tend to be. (Run hundreds of concurrent database server processes, about a third of them under rr record, and bombard each one with some client requests for a few minutes, then kill and restart the servers, and check that the recovery works fine.)

Keno commented 1 year ago

If there's a known kernel version difference, I'd grep the changelist for any changes to the handling of TIF_SIGPENDING to see if something made the fix in https://github.com/rr-debugger/rr/pull/3148 ineffective.

dr-m commented 1 year ago

This is the kernel version that our trace was recorded and replayed on:

Linux version 5.15.0-52-generic (buildd@lcy02-amd64-032) (gcc (Ubuntu 11.2.0-19ubuntu1) 11.2.0, GNU ld (GNU Binutils for Ubuntu) 2.38) #58-Ubuntu SMP Thu Oct 13 08:03:55 UTC 2022
dr-m commented 1 year ago

(Un)fortunately, for us this error occurs extremely rarely, at most 4 times for 500,000 test runs. The system where the rr record is run is very often overloaded (hundreds or thousands of processes running concurrently).

Hopefully someone who is more affected by this can provide repeatable steps for reproducing this.