rr-debugger / rr-debugger/rr

Support for RDMA syscalls

Open
#3,937 6 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
C++
Stars
10.7k
Forks
662
Avg merge
2d 3h
Merged PRs (30d)
2

Description

With https://github.com/rr-debugger/rr/tree/5.8.0 I get this failure on an application that uses OpenMPI.

According to ^1 the failing syscall 0xc0181b01 is RDMA_VERBS_IOCTL.

[FATAL src/record_syscall.cc:6556:rec_process_syscall_arch()]
 (task 758000 (rec:758000) at time 8712)
 -> Assertion `t->regs().syscall_result_signed() == -syscall_state.expect_errno' failed to hold. Expected EINVAL for 'ioctl' but got result -28 (errno ENOSPC); Unknown ioctl(0xc0181b01): type:0x1b nr:0x1 dir:0x3 size:24 addr:0x7fff35dd9de0
Tail of trace dump:
{
  real_time:3779123.805374 global_time:8692, event:`SYSCALL: bind' (state:ENTERING_SYSCALL) tid:758000, ticks:23592850
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0xc rsi:0x147f900 rdi:0xc rbp:0xb04b90f0 rsp:0x681ffde0 r8:0x1500a733d160 r9:0x0 r10:0x20 r11:0x246 r12:0x14 r13:0x7fff35dd9e70 r14:0x6 r15:0x1 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x31 fs_base:0x1500a7bc3940 gs_base:0x0
}
{
  real_time:3779123.805381 global_time:8693, event:`SYSCALLBUF_RESET' tid:758000, ticks:23592850
}
{
  real_time:3779123.805402 global_time:8694, event:`SYSCALL: bind' (state:EXITING_SYSCALL) tid:758000, ticks:23592850
rax:0x0 rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0xc rsi:0x147f900 rdi:0xc rbp:0xb04b90f0 rsp:0x681ffde0 r8:0x1500a733d160 r9:0x0 r10:0x20 r11:0x246 r12:0x14 r13:0x7fff35dd9e70 r14:0x6 r15:0x1 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x31 fs_base:0x1500a7bc3940 gs_base:0x0
}
{
  real_time:3779123.805529 global_time:8695, event:`SYSCALLBUF_FLUSH' tid:758000, ticks:23603017
  { syscall:'getsockname', ret:0x0, size:0x20, desched:1 }
  { syscall:'sendmsg', ret:0x10, size:0x10, desched:1 }
  { syscall:'recvmsg', ret:0x80, size:0xe4, desched:1 }
  { syscall:'recvmsg', ret:0x88, size:0xec, desched:1 }
  { syscall:'recvmsg', ret:0x14, size:0x78, desched:1 }
  { syscall:'sendmsg', ret:0x24, size:0x10, desched:1 }
  { syscall:'recvmsg', ret:0x3c, size:0xa0, desched:1 }
  { syscall:'fstatat', ret:0x0, size:0xa0 }
  { syscall:'sendmsg', ret:0x24, size:0x10, desched:1 }
  { syscall:'recvmsg', ret:0x3c, size:0xa0, desched:1 }
  { syscall:'fstatat', ret:0x0, size:0xa0 }
  { syscall:'close', ret:0x0, size:0x10 }
  { syscall:'time', ret:0x67e3c0f7, size:0x10 }
}
{
  real_time:3779123.805537 global_time:8696, event:`SYSCALL: socket' (state:ENTERING_SYSCALL) tid:758000, ticks:23603017
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x14 rsi:0x80003 rdi:0x10 rbp:0x147f900 rsp:0x681ffde0 r8:0x67e3c0f7 r9:0x0 r10:0x3 r11:0x246 r12:0x14 r13:0x7fff35dda1c8 r14:0x0 r15:0x14727d0 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x29 fs_base:0x1500a7bc3940 gs_base:0x0
}
{
  real_time:3779123.805546 global_time:8697, event:`SYSCALLBUF_RESET' tid:758000, ticks:23603017
}
{
  real_time:3779123.805571 global_time:8698, event:`SYSCALL: socket' (state:EXITING_SYSCALL) tid:758000, ticks:23603017
rax:0xc rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x14 rsi:0x80003 rdi:0x10 rbp:0x147f900 rsp:0x681ffde0 r8:0x67e3c0f7 r9:0x0 r10:0x3 r11:0x246 r12:0x14 r13:0x7fff35dda1c8 r14:0x0 r15:0x14727d0 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x29 fs_base:0x1500a7bc3940 gs_base:0x0
}
{
  real_time:3779123.805604 global_time:8699, event:`SYSCALLBUF_FLUSH' tid:758000, ticks:23603129
  { syscall:'setsockopt', ret:0x0, size:0x10, desched:1 }
  { syscall:'setsockopt', ret:0x0, size:0x10, desched:1 }
  { syscall:'getpid', ret:0xb90f0, size:0x10 }
}
{
  real_time:3779123.805610 global_time:8700, event:`SYSCALL: bind' (state:ENTERING_SYSCALL) tid:758000, ticks:23603129
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0xc rsi:0x147f900 rdi:0xc rbp:0xdb0b90f0 rsp:0x681ffde0 r8:0x1500a733d160 r9:0x0 r10:0x20 r11:0x246 r12:0x14 r13:0x7fff35dd9ff0 r14:0x6 r15:0x1 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x31 fs_base:0x1500a7bc3940 gs_base:0x0
}
{
  real_time:3779123.805618 global_time:8701, event:`SYSCALLBUF_RESET' tid:758000, ticks:23603129
}
{
  real_time:3779123.805638 global_time:8702, event:`SYSCALL: bind' (state:EXITING_SYSCALL) tid:758000, ticks:23603129
rax:0x0 rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0xc rsi:0x147f900 rdi:0xc rbp:0xdb0b90f0 rsp:0x681ffde0 r8:0x1500a733d160 r9:0x0 r10:0x20 r11:0x246 r12:0x14 r13:0x7fff35dd9ff0 r14:0x6 r15:0x1 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x31 fs_base:0x1500a7bc3940 gs_base:0x0
}
{
  real_time:3779123.805702 global_time:8703, event:`SYSCALLBUF_FLUSH' tid:758000, ticks:23608486
  { syscall:'getsockname', ret:0x0, size:0x20, desched:1 }
  { syscall:'sendmsg', ret:0x10, size:0x10, desched:1 }
  { syscall:'recvmsg', ret:0x30, size:0x94, desched:1 }
  { syscall:'close', ret:0x0, size:0x10 }
}
{
  real_time:3779123.805709 global_time:8704, event:`SYSCALL: openat' (state:ENTERING_SYSCALL) tid:758000, ticks:23608486
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x80002 rsi:0x147f410 rdi:0xffffff9c rbp:0x147f410 rsp:0x681ffde0 r8:0x0 r9:0x20 r10:0x0 r11:0x246 r12:0x80002 r13:0x7fff35dd9fb0 r14:0x0 r15:0x7fff35dda1c8 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x101 fs_base:0x1500a7bc3940 gs_base:0x0
}
{
  real_time:3779123.805716 global_time:8705, event:`SYSCALLBUF_RESET' tid:758000, ticks:23608486
}
{
  real_time:3779123.805906 global_time:8706, event:`SYSCALL: openat' (state:EXITING_SYSCALL) tid:758000, ticks:23608486
rax:0xc rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x80002 rsi:0x147f410 rdi:0xffffff9c rbp:0x147f410 rsp:0x681ffde0 r8:0x0 r9:0x20 r10:0x0 r11:0x246 r12:0x80002 r13:0x7fff35dd9fb0 r14:0x0 r15:0x7fff35dda1c8 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x101 fs_base:0x1500a7bc3940 gs_base:0x0
}
{
  real_time:3779123.805944 global_time:8707, event:`SYSCALLBUF_FLUSH' tid:758000, ticks:23608609
  { syscall:'fstat', ret:0x0, size:0xa0 }
}
{
  real_time:3779123.805951 global_time:8708, event:`SYSCALL: mmap' (state:ENTERING_SYSCALL) tid:758000, ticks:23608609
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x3 rsi:0x42000 rdi:0x0 rbp:0x1 rsp:0x681ffde0 r8:0xffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x1500a74b7530 r13:0x7fff35dd9c10 r14:0xffffffff r15:0x2200000003 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0x1500a7bc3940 gs_base:0x0
}
{
  real_time:3779123.805958 global_time:8709, event:`SYSCALLBUF_RESET' tid:758000, ticks:23608609
}
{
  real_time:3779123.805986 global_time:8710, event:`SYSCALL: mmap' (state:EXITING_SYSCALL) tid:758000, ticks:23608609
rax:0x1500a71d0000 rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x3 rsi:0x42000 rdi:0x0 rbp:0x1 rsp:0x681ffde0 r8:0xffffffff r9:0x0 r10:0x22 r11:0x246 r12:0x1500a74b7530 r13:0x7fff35dd9c10 r14:0xffffffff r15:0x2200000003 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x9 fs_base:0x1500a7bc3940 gs_base:0x0
  { map_file:"<ZERO>", addr:0x1500a71d0000, length:0x42000, prot_flags:"rw-p", file_offset:0x0, device:0, inode:0, data_file:"", data_offset:0x0, file_size:0x42000 }
}
{
  real_time:3779123.806075 global_time:8711, event:`SYSCALL: ioctl' (state:ENTERING_SYSCALL) tid:758000, ticks:23608814
rax:0xffffffffffffffda rbx:0x681fffa0 rcx:0xffffffffffffffff rdx:0x7fff35dd9de0 rsi:0xc0181b01 rdi:0xc rbp:0x7fff35dd9dc0 rsp:0x681ffdc0 r8:0x1500a71d0010 r9:0x0 r10:0x22 r11:0x246 r12:0x1500a71d0010 r13:0x1482ed0 r14:0x1 r15:0x1478e40 rip:0x70000002 eflags:0x246 cs:0x33 ss:0x2b ds:0x0 es:0x0 fs:0x0 gs:0x0 orig_rax:0x10 fs_base:0x1500a7bc3940 gs_base:0x0
}
=== Start rr backtrace:
rr(_ZN2rr13dump_rr_stackEv+0x28)[0x639a98]
rr(_ZN2rr15emergency_debugEPNS_4TaskE+0x113)[0x521b13]
rr[0x529d6d]
rr[0x529f4b]
rr[0x529f89]
rr[0x58d73d]
rr(_ZN2rr19rec_process_syscallEPNS_10RecordTaskE+0x115)[0x563825]
rr(_ZN2rr13RecordSession21syscall_state_changedEPNS_10RecordTaskEPNS0_9StepStateE+0x31a)[0x54fbda]
rr(_ZN2rr13RecordSession11record_stepEv+0x5c8)[0x559dd8]
rr(_ZN2rr13RecordCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0xc3e)[0x54acee]
rr(main+0x181)[0x4aac61]
/lib64/libc.so.6(+0x29590)[0x15383c029590]
/lib64/libc.so.6(__libc_start_main+0x80)[0x15383c029640]
rr(_start+0x25)[0x4ad395]
=== End rr backtrace

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start in src/record_syscall.cc around rec_process_syscall_arch() at the reported assertion, then compare the RDMA_VERBS_IOCTL definition in the linked strace ioctls_inc.h entry. Reproduce with the OpenMPI application and verify that recording proceeds past ioctl(0xc0181b01) without the assertion.

Written by the indexing model from the issue text.

Assessment

Tech stack
cpp, linux
Domain
networking, operating-systems
Issue type
Feature
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.