Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

can't run in docker #2387

Closed
alehander92 opened this issue Sep 17, 2019 · 17 comments
Closed

can't run in docker #2387

alehander92 opened this issue Sep 17, 2019 · 17 comments

Comments

@alehander92
Copy link
Contributor

alehander92 commented Sep 17, 2019 •
edited
Loading

running rr recording ls

sudo docker run --cap-add SYS_PTRACE --security-opt seccomp:unconfined -v /home/al/codetracer_cache:/codetracer  -it codetracer

[FATAL ../src/RecordTask.cc:1507:record_remote() errno: EISDIR] 
 (task 26 (rec:26) at time 14)
 -> Assertion `num_bytes >= 0' failed to hold. 
Tail of trace dump:
=== Start rr backtrace:
libs/rr/bin/rr(_ZN2rr13dump_rr_stackEv+0x44)[0x561a230683d8]
libs/rr/bin/rr(_ZN2rr9GdbServer15emergency_debugEPNS_4TaskE+0x1a2)[0x561a22eebfb6]
libs/rr/bin/rr(+0x307c48)[0x561a22f11c48]
libs/rr/bin/rr(_ZN2rr21EmergencyDebugOstreamD1Ev+0x62)[0x561a22f11ea2]
libs/rr/bin/rr(_ZN2rr10RecordTask13record_remoteENS_10remote_ptrIvEEl+0x80)[0x561a22fb5ebc]
libs/rr/bin/rr(+0x35ed5b)[0x561a22f68d5b]
libs/rr/bin/rr(+0x374d78)[0x561a22f7ed78]
libs/rr/bin/rr(+0x3622e5)[0x561a22f6c2e5]
libs/rr/bin/rr(_ZN2rr19rec_process_syscallEPNS_10RecordTaskE+0xe8)[0x561a22f6c3d0]
libs/rr/bin/rr(_ZN2rr13RecordSession21syscall_state_changedEPNS_10RecordTaskEPNS0_9StepStateE+0xfc8)[0x561a22f5096c]
libs/rr/bin/rr(_ZN2rr13RecordSession11record_stepEv+0x598)[0x561a22f55b26]
libs/rr/bin/rr(+0x33e880)[0x561a22f48880]
libs/rr/bin/rr(_ZN2rr13RecordCommand3runERSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS7_EE+0x2d5)[0x561a22f4934f]
libs/rr/bin/rr(main+0x21b)[0x561a2307fc89]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xeb)[0x7f4c9536db6b]
libs/rr/bin/rr(_start+0x2a)[0x561a22e5e57a]
=== End rr backtrace
Launch gdb with
  gdb '-l' '10000' '-ex' 'set sysroot /' '-ex' 'target extended-remote 127.0.0.1:26' /usr/bin/ls
^C

I used it succesfully in docker before, so i wonder what can lead to that error so i can debug
@alehander92
Copy link
Contributor Author

(added some info as edit in github)

@khuey
Copy link
Collaborator

khuey commented Sep 17, 2019

What version of docker is this?

@alehander92
Copy link
Contributor Author

alehander92 commented Sep 17, 2019 •
edited
Loading

Thank you !

Docker version 18.09.7, build 2d0083d

I tried to debug and it seems the num_bytes arg is becoming a negative number in process_execve but not sure what it means

@khuey
Copy link
Collaborator

khuey commented Sep 17, 2019

My guess would be that the /proc filesystem inside the container is not available for some reason, and that we're dying trying to record values from the /proc/<pid>/mem of the tracee (ls in this case).

Can you run it again with RR_LOG=debug in the environment and put that somewhere?

@alehander92
Copy link
Contributor Author

ok, but .. where does this log to?

@alehander92
Copy link
Contributor Author

RR_LOG_FILE=log produces an empty file

@alehander92
Copy link
Contributor Author

sorry, didn't think of combining it:

RR_LOG=all RR_LOG_FILE=log <my rr> record ls

root@730c5ac69a38:/codetracer# cat log
[GdbCommandHandler] registering command: elapsed-time
[GdbCommandHandler] registering command: when
[GdbCommandHandler] registering command: when-ticks
[GdbCommandHandler] registering command: when-tid
[GdbCommandHandler] registering command: rr-history-push
[GdbCommandHandler] registering command: back
[GdbCommandHandler] registering command: forward
[GdbCommandHandler] registering command: checkpoint
[GdbCommandHandler] registering command: delete checkpoint
[GdbCommandHandler] registering command: info checkpoints
[INFO record()] Start recording...
[util] CPUID faulting works
[PerfCounters] has_ioc_period_bug=0
[PerfCounters] supports txcp=1
[PerfCounters] has_kvm_in_txcp_bug=0 count=1020
[PerfCounters] only_one_counter=0
[Session] Session 0x5651093dc540 created
[ThreadGroup] creating new thread group 226 (real tgid:226)
[HasTaskSet] adding 226 to task set 0x5651093e0340
[HasTaskSet] adding 226 to task set 0x5651093db680
[HasTaskSet] adding 226 to task set 0x5651093d9f60
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x137f (STOP-SIGSTOP)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] syscall openat
[RecordTask] Refreshed sigmask, now 0
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] Used enter_syscall; status=0x857f (SYSCALL)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] syscall exit status=0x857f (SYSCALL)
[AutoRemoteSyscalls] done, result=15
[AutoRemoteSyscalls] syscall sendmsg
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] Used enter_syscall; status=0x857f (SYSCALL)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] syscall exit status=0x857f (SYSCALL)
[AutoRemoteSyscalls] done, result=1
[AutoRemoteSyscalls] syscall close
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] Used enter_syscall; status=0x857f (SYSCALL)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] syscall exit status=0x857f (SYSCALL)
[AutoRemoteSyscalls] done, result=0
[Scheduler] Scheduling next task
[Scheduler]   need to reschedule
[Scheduler]   226 isn't blocked
[Scheduler]   selecting task 226
[RecordSession] trace time 1: Active task is 226. Events:
[INFO log_pending_events()] (no pending events)
[RecordSession] EXEC_START: status=0 (EXIT-0)
[PerfCounters] Recreating counters with period 285118
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period 285118
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at (none))
[Scheduler]   and running; waiting for state change
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[Scheduler]   new status is 0x857f (SYSCALL)
[RecordSession] trace time 1: Active task is 226. Events:
[INFO log_pending_events()] (no pending events)
[RecordSession] EXEC_SYSCALL_ENTRY: status=0x857f (SYSCALL)
[RecordTask] Wrote event SYSCALL: prctl for time 1
[RecordSession] after cont: status=0x857f (SYSCALL)
[RecordSession] EXEC_START: status=0x857f (SYSCALL)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at SYSCALL: prctl)
[Scheduler]   and running; waiting for state change
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[Scheduler]   new status is 0x857f (SYSCALL)
[RecordSession] trace time 2: Active task is 226. Events:
[INFO log()] SYSCALL: prctl
[INFO log()] (none)
[RecordSession] EXEC_IN_SYSCALL: status=0x857f (SYSCALL)
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at SYSCALL: prctl)
[RecordSession] trace time 2: Active task is 226. Events:
[INFO log()] SYSCALL: prctl
[INFO log()] (none)
[RecordSession] EXEC_SYSCALL_DONE: status=0x857f (SYSCALL)
[RecordSession]   original_syscallno:157 (prctl); return val:0
[record_syscall] 226: processing: SYSCALL: prctl -- time: 2
[RecordTask] Wrote event SYSCALL: prctl for time 2
[Scheduler] Scheduling next task
[Scheduler]   226 isn't blocked
[Scheduler]   Carrying on with task 226
[RecordSession] trace time 3: Active task is 226. Events:
[INFO log_pending_events()] (no pending events)
[RecordSession] EXEC_START: status=0x857f (SYSCALL)
[PerfCounters] Resetting counters with period 285117
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period 285117
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at (none))
[Scheduler]   and running; waiting for state change
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[Scheduler]   new status is 0x857f (SYSCALL)
[RecordSession] trace time 3: Active task is 226. Events:
[INFO log_pending_events()] (no pending events)
[RecordSession] EXEC_START: status=0x857f (SYSCALL)
[PerfCounters] Resetting counters with period 285098
[Task] resuming execution of 226 with PTRACE_CONT tick_period 285098
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at (none))
[Scheduler]   and running; waiting for state change
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[Scheduler]   new status is 0x7057f (PTRACE_EVENT_SECCOMP)
[RecordSession] trace time 3: Active task is 226. Events:
[INFO log_pending_events()] (no pending events)
[RecordSession]   226: handle_ptrace_event PTRACE_EVENT_SECCOMP: event (none)
[RecordSession]   traced syscall entered: write
[RecordSession] EXEC_SYSCALL_ENTRY: status=0x7057f (PTRACE_EVENT_SECCOMP)
[RecordTask] Wrote event SYSCALL: write for time 3
[RecordSession] after cont: status=0x7057f (PTRACE_EVENT_SECCOMP)
[RecordSession] EXEC_START: status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Scheduler] Scheduling next task
[Scheduler]   226 is blocked on SYSCALL: write; checking status ...
[Task] waitpid(226, NOHANG) returns 0, status 0 (EXIT-0)
[Scheduler]   still blocked
[Scheduler]   need to reschedule
[Scheduler]   226 is blocked on SYSCALL: write; checking status ...
[Task] waitpid(226, NOHANG) returns 0, status 0 (EXIT-0)
[Scheduler]   still blocked
[Scheduler]   all tasks blocked or some unstable, waiting for runnable (1 total)
[Scheduler]   226 changed status to 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[RecordSession] trace time 4: Active task is 226. Events:
[INFO log()] SYSCALL: write
[INFO log()] (none)
[RecordSession] EXEC_IN_SYSCALL: status=0x857f (SYSCALL)
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at SYSCALL: write)
[RecordSession] trace time 4: Active task is 226. Events:
[INFO log()] SYSCALL: write
[INFO log()] (none)
[RecordSession] EXEC_SYSCALL_DONE: status=0x857f (SYSCALL)
[RecordSession]   original_syscallno:1 (write); return val:0xfffffffffffffff7
[record_syscall] 226: processing: SYSCALL: write -- time: 4
[RecordTask] Wrote event SYSCALL: write for time 4
[Scheduler] Scheduling next task
[Scheduler]   226 isn't blocked
[Scheduler]   Carrying on with task 226
[RecordSession] trace time 5: Active task is 226. Events:
[INFO log_pending_events()] (no pending events)
[RecordSession] EXEC_START: status=0x857f (SYSCALL)
[PerfCounters] Resetting counters with period 488709
[Task] resuming execution of 226 with PTRACE_CONT tick_period 488709
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at (none))
[Scheduler]   and running; waiting for state change
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[Scheduler]   new status is 0x7057f (PTRACE_EVENT_SECCOMP)
[RecordSession] trace time 5: Active task is 226. Events:
[INFO log_pending_events()] (no pending events)
[RecordSession]   226: handle_ptrace_event PTRACE_EVENT_SECCOMP: event (none)
[RecordSession]   traced syscall entered: geteuid
[RecordSession] EXEC_SYSCALL_ENTRY: status=0x7057f (PTRACE_EVENT_SECCOMP)
[RecordTask] Wrote event SYSCALL: geteuid for time 5
[RecordSession] after cont: status=0x7057f (PTRACE_EVENT_SECCOMP)
[RecordSession] EXEC_START: status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at SYSCALL: geteuid)
[Scheduler]   and running; waiting for state change
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[Scheduler]   new status is 0x857f (SYSCALL)
[RecordSession] trace time 6: Active task is 226. Events:
[INFO log()] SYSCALL: geteuid
[INFO log()] (none)
[RecordSession] EXEC_IN_SYSCALL: status=0x857f (SYSCALL)
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at SYSCALL: geteuid)
[RecordSession] trace time 6: Active task is 226. Events:
[INFO log()] SYSCALL: geteuid
[INFO log()] (none)
[RecordSession] EXEC_SYSCALL_DONE: status=0x857f (SYSCALL)
[RecordSession]   original_syscallno:107 (geteuid); return val:0
[record_syscall] 226: processing: SYSCALL: geteuid -- time: 6
[RecordTask] Wrote event SYSCALL: geteuid for time 6
[Scheduler] Scheduling next task
[Scheduler]   226 isn't blocked
[Scheduler]   Carrying on with task 226
[RecordSession] trace time 7: Active task is 226. Events:
[INFO log_pending_events()] (no pending events)
[RecordSession] EXEC_START: status=0x857f (SYSCALL)
[PerfCounters] Resetting counters with period 488707
[Task] resuming execution of 226 with PTRACE_CONT tick_period 488707
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at (none))
[Scheduler]   and running; waiting for state change
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[Scheduler]   new status is 0x7057f (PTRACE_EVENT_SECCOMP)
[RecordSession] trace time 7: Active task is 226. Events:
[INFO log_pending_events()] (no pending events)
[RecordSession]   226: handle_ptrace_event PTRACE_EVENT_SECCOMP: event (none)
[RecordSession]   traced syscall entered: geteuid
[RecordSession] EXEC_SYSCALL_ENTRY: status=0x7057f (PTRACE_EVENT_SECCOMP)
[RecordTask] Wrote event SYSCALL: geteuid for time 7
[RecordSession] after cont: status=0x7057f (PTRACE_EVENT_SECCOMP)
[RecordSession] EXEC_START: status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at SYSCALL: geteuid)
[Scheduler]   and running; waiting for state change
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[Scheduler]   new status is 0x857f (SYSCALL)
[RecordSession] trace time 8: Active task is 226. Events:
[INFO log()] SYSCALL: geteuid
[INFO log()] (none)
[RecordSession] EXEC_IN_SYSCALL: status=0x857f (SYSCALL)
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at SYSCALL: geteuid)
[RecordSession] trace time 8: Active task is 226. Events:
[INFO log()] SYSCALL: geteuid
[INFO log()] (none)
[RecordSession] EXEC_SYSCALL_DONE: status=0x857f (SYSCALL)
[RecordSession]   original_syscallno:107 (geteuid); return val:0
[record_syscall] 226: processing: SYSCALL: geteuid -- time: 8
[RecordTask] Wrote event SYSCALL: geteuid for time 8
[Scheduler] Scheduling next task
[Scheduler]   226 isn't blocked
[Scheduler]   Carrying on with task 226
[RecordSession] trace time 9: Active task is 226. Events:
[INFO log_pending_events()] (no pending events)
[RecordSession] EXEC_START: status=0x857f (SYSCALL)
[PerfCounters] Resetting counters with period 488705
[Task] resuming execution of 226 with PTRACE_CONT tick_period 488705
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at (none))
[Scheduler]   and running; waiting for state change
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[Scheduler]   new status is 0x7057f (PTRACE_EVENT_SECCOMP)
[RecordSession] trace time 9: Active task is 226. Events:
[INFO log_pending_events()] (no pending events)
[RecordSession]   226: handle_ptrace_event PTRACE_EVENT_SECCOMP: event (none)
[RecordSession]   traced syscall entered: geteuid
[RecordSession] EXEC_SYSCALL_ENTRY: status=0x7057f (PTRACE_EVENT_SECCOMP)
[RecordTask] Wrote event SYSCALL: geteuid for time 9
[RecordSession] after cont: status=0x7057f (PTRACE_EVENT_SECCOMP)
[RecordSession] EXEC_START: status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at SYSCALL: geteuid)
[Scheduler]   and running; waiting for state change
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[Scheduler]   new status is 0x857f (SYSCALL)
[RecordSession] trace time 10: Active task is 226. Events:
[INFO log()] SYSCALL: geteuid
[INFO log()] (none)
[RecordSession] EXEC_IN_SYSCALL: status=0x857f (SYSCALL)
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at SYSCALL: geteuid)
[RecordSession] trace time 10: Active task is 226. Events:
[INFO log()] SYSCALL: geteuid
[INFO log()] (none)
[RecordSession] EXEC_SYSCALL_DONE: status=0x857f (SYSCALL)
[RecordSession]   original_syscallno:107 (geteuid); return val:0
[record_syscall] 226: processing: SYSCALL: geteuid -- time: 10
[RecordTask] Wrote event SYSCALL: geteuid for time 10
[Scheduler] Scheduling next task
[Scheduler]   226 isn't blocked
[Scheduler]   Carrying on with task 226
[RecordSession] trace time 11: Active task is 226. Events:
[INFO log_pending_events()] (no pending events)
[RecordSession] EXEC_START: status=0x857f (SYSCALL)
[PerfCounters] Resetting counters with period 488703
[Task] resuming execution of 226 with PTRACE_CONT tick_period 488703
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at (none))
[Scheduler]   and running; waiting for state change
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[Scheduler]   new status is 0x7057f (PTRACE_EVENT_SECCOMP)
[RecordSession] trace time 11: Active task is 226. Events:
[INFO log_pending_events()] (no pending events)
[RecordSession]   226: handle_ptrace_event PTRACE_EVENT_SECCOMP: event (none)
[RecordSession]   traced syscall entered: geteuid
[RecordSession] EXEC_SYSCALL_ENTRY: status=0x7057f (PTRACE_EVENT_SECCOMP)
[RecordTask] Wrote event SYSCALL: geteuid for time 11
[RecordSession] after cont: status=0x7057f (PTRACE_EVENT_SECCOMP)
[RecordSession] EXEC_START: status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at SYSCALL: geteuid)
[Scheduler]   and running; waiting for state change
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[Scheduler]   new status is 0x857f (SYSCALL)
[RecordSession] trace time 12: Active task is 226. Events:
[INFO log()] SYSCALL: geteuid
[INFO log()] (none)
[RecordSession] EXEC_IN_SYSCALL: status=0x857f (SYSCALL)
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at SYSCALL: geteuid)
[RecordSession] trace time 12: Active task is 226. Events:
[INFO log()] SYSCALL: geteuid
[INFO log()] (none)
[RecordSession] EXEC_SYSCALL_DONE: status=0x857f (SYSCALL)
[RecordSession]   original_syscallno:107 (geteuid); return val:0
[record_syscall] 226: processing: SYSCALL: geteuid -- time: 12
[RecordTask] Wrote event SYSCALL: geteuid for time 12
[Scheduler] Scheduling next task
[Scheduler]   226 isn't blocked
[Scheduler]   Carrying on with task 226
[RecordSession] trace time 13: Active task is 226. Events:
[INFO log_pending_events()] (no pending events)
[RecordSession] EXEC_START: status=0x857f (SYSCALL)
[PerfCounters] Resetting counters with period 488701
[Task] resuming execution of 226 with PTRACE_CONT tick_period 488701
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at (none))
[Scheduler]   and running; waiting for state change
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[Scheduler]   new status is 0x7057f (PTRACE_EVENT_SECCOMP)
[RecordSession] trace time 13: Active task is 226. Events:
[INFO log_pending_events()] (no pending events)
[RecordSession]   226: handle_ptrace_event PTRACE_EVENT_SECCOMP: event (none)
[RecordSession]   traced syscall entered: execve
[RecordSession] EXEC_SYSCALL_ENTRY: status=0x7057f (PTRACE_EVENT_SECCOMP)
[RecordTask] Wrote event SYSCALL: execve for time 13
[RecordSession] after cont: status=0x7057f (PTRACE_EVENT_SECCOMP)
[RecordSession] EXEC_START: status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Scheduler] Scheduling next task
[Scheduler]   226 is blocked on SYSCALL: execve; checking status ...
[Task] waitpid(226, NOHANG) returns 0, status 0 (EXIT-0)
[Scheduler]   still blocked
[Scheduler]   need to reschedule
[Scheduler]   226 is blocked on SYSCALL: execve; checking status ...
[Task] waitpid(226, NOHANG) returns 0, status 0 (EXIT-0)
[Scheduler]   still blocked
[Scheduler]   all tasks blocked or some unstable, waiting for runnable (1 total)
[Scheduler]   226 changed status to 0x4057f (PTRACE_EVENT_EXEC)
[Task]   (refreshing register cache)
[RecordSession] trace time 14: Active task is 226. Events:
[INFO log()] SYSCALL: execve
[INFO log()] (none)
[RecordSession]   226: handle_ptrace_event PTRACE_EVENT_EXEC: event SYSCALL: execve
[HasTaskSet] removing 226 from task set 0x5651093db680
[HasTaskSet] removing 226 from task set 0x5651093d9f60
[Task]   (refreshing extra-register cache using XSAVE)
[AddressSpace] mmap(0x55d267fd8000, 16384, 0x1, 0x2, 0)
[AddressSpace] munmap(0x55d267fd8000, 16384)
[AddressSpace]   not found, done.
[AddressSpace]   mapping 0x55d267fd8000-0x55d267fdc000 r--p 00000000 00:40 4985254    /
[AddressSpace]   no mappings to coalesce
[AddressSpace] mmap(0x55d267fdc000, 77824, 0x5, 0x2, 0x4000)
[AddressSpace] munmap(0x55d267fdc000, 77824)
[AddressSpace]   not found, done.
[AddressSpace]   mapping 0x55d267fdc000-0x55d267fef000 r-xp 00004000 00:40 4985254    /
[AddressSpace]   no mappings to coalesce
[AddressSpace] mmap(0x55d267fef000, 36864, 0x1, 0x2, 0x17000)
[AddressSpace] munmap(0x55d267fef000, 36864)
[AddressSpace]   not found, done.
[AddressSpace]   mapping 0x55d267fef000-0x55d267ff8000 r--p 00017000 00:40 4985254    /
[AddressSpace]   no mappings to coalesce
[AddressSpace] mmap(0x55d267ff9000, 8192, 0x3, 0x2, 0x20000)
[AddressSpace] munmap(0x55d267ff9000, 8192)
[AddressSpace]   not found, done.
[AddressSpace]   mapping 0x55d267ff9000-0x55d267ffb000 rw-p 00020000 00:40 4985254    /
[AddressSpace]   no mappings to coalesce
[AddressSpace] mmap(0x55d267ffb000, 4096, 0x3, 0x2, 0)
[AddressSpace] munmap(0x55d267ffb000, 4096)
[AddressSpace]   not found, done.
[AddressSpace]   mapping 0x55d267ffb000-0x55d267ffc000 rw-p 00000000 00:00 0          
[AddressSpace]   no mappings to coalesce
[AddressSpace] mmap(0x7f70de929000, 4096, 0x1, 0x2, 0)
[AddressSpace] munmap(0x7f70de929000, 4096)
[AddressSpace]   not found, done.
[AddressSpace]   mapping 0x7f70de929000-0x7f70de92a000 r--p 00000000 00:40 5258735    /
[AddressSpace]   no mappings to coalesce
[AddressSpace] mmap(0x7f70de92a000, 135168, 0x5, 0x2, 0x1000)
[AddressSpace] munmap(0x7f70de92a000, 135168)
[AddressSpace]   not found, done.
[AddressSpace]   mapping 0x7f70de92a000-0x7f70de94b000 r-xp 00001000 00:40 5258735    /
[AddressSpace]   no mappings to coalesce
[AddressSpace] mmap(0x7f70de94b000, 32768, 0x1, 0x2, 0x22000)
[AddressSpace] munmap(0x7f70de94b000, 32768)
[AddressSpace]   not found, done.
[AddressSpace]   mapping 0x7f70de94b000-0x7f70de953000 r--p 00022000 00:40 5258735    /
[AddressSpace]   no mappings to coalesce
[AddressSpace] mmap(0x7f70de953000, 8192, 0x3, 0x2, 0x29000)
[AddressSpace] munmap(0x7f70de953000, 8192)
[AddressSpace]   not found, done.
[AddressSpace]   mapping 0x7f70de953000-0x7f70de955000 rw-p 00029000 00:40 5258735    /
[AddressSpace]   no mappings to coalesce
[AddressSpace] mmap(0x7f70de955000, 4096, 0x3, 0x2, 0)
[AddressSpace] munmap(0x7f70de955000, 4096)
[AddressSpace]   not found, done.
[AddressSpace]   mapping 0x7f70de955000-0x7f70de956000 rw-p 00000000 00:00 0          
[AddressSpace]   no mappings to coalesce
[AddressSpace] mmap(0x7ffd84fd7000, 139264, 0x3, 0x102, 0)
[AddressSpace] munmap(0x7ffd84fd7000, 139264)
[AddressSpace]   not found, done.
[AddressSpace]   mapping 0x7ffd84fd7000-0x7ffd84ff9000 rw-p 00000000 00:00 0          [stack]
[AddressSpace]   no mappings to coalesce
[AddressSpace] mmap(0x7ffd84ffa000, 12288, 0x1, 0x2, 0)
[AddressSpace] munmap(0x7ffd84ffa000, 12288)
[AddressSpace]   not found, done.
[AddressSpace]   mapping 0x7ffd84ffa000-0x7ffd84ffd000 r--p 00000000 00:00 0          [vvar]
[AddressSpace]   no mappings to coalesce
[AddressSpace] mmap(0x7ffd84ffd000, 4096, 0x5, 0x2, 0)
[AddressSpace] munmap(0x7ffd84ffd000, 4096)
[AddressSpace]   not found, done.
[AddressSpace]   mapping 0x7ffd84ffd000-0x7ffd84ffe000 r-xp 00000000 00:00 0          [vdso]
[AddressSpace]   no mappings to coalesce
[AddressSpace] mmap(0xffffffffff600000, 4096, 0x5, 0x2, 0)
[AddressSpace] munmap(0xffffffffff600000, 4096)
[AddressSpace]   not found, done.
[AddressSpace]   mapping 0xffffffffff600000-0xffffffffff601000 r-xp 00000000 00:00 0          [vsyscall]
[AddressSpace]   no mappings to coalesce
[HasTaskSet] adding 226 to task set 0x5651093e1150
[HasTaskSet] adding 226 to task set 0x5651093e0af0
[RecordSession] EXEC_START: status=0x4057f (PTRACE_EVENT_EXEC)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at SYSCALL: execve)
[Scheduler]   and running; waiting for state change
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[Scheduler]   new status is 0x857f (SYSCALL)
[RecordSession] trace time 14: Active task is 226. Events:
[INFO log()] SYSCALL: execve
[INFO log()] (none)
[RecordSession] EXEC_IN_SYSCALL: status=0x857f (SYSCALL)
[Scheduler] Scheduling next task
[Scheduler]   (226 is un-switchable at SYSCALL: execve)
[RecordSession] trace time 14: Active task is 226. Events:
[INFO log()] SYSCALL: execve
[INFO log()] (none)
[RecordSession] EXEC_SYSCALL_DONE: status=0x857f (SYSCALL)
[RecordSession]   original_syscallno:59 (execve); return val:0
[record_syscall] 226: processing: SYSCALL: execve -- time: 14
[AutoRemoteSyscalls] syscall openat
[Task] resuming execution of 226 with PTRACE_CONT tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] Used enter_syscall; status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] syscall exit status=0x857f (SYSCALL)
[AutoRemoteSyscalls] done, result=4
[AutoRemoteSyscalls] syscall sendmsg
[Task] resuming execution of 226 with PTRACE_CONT tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] Used enter_syscall; status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] syscall exit status=0x857f (SYSCALL)
[AutoRemoteSyscalls] done, result=1
[AutoRemoteSyscalls] syscall close
[Task] resuming execution of 226 with PTRACE_CONT tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] Used enter_syscall; status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] syscall exit status=0x857f (SYSCALL)
[AutoRemoteSyscalls] done, result=0
[AutoRemoteSyscalls] syscall openat
[Task] resuming execution of 226 with PTRACE_CONT tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] Used enter_syscall; status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] syscall exit status=0x857f (SYSCALL)
[AutoRemoteSyscalls] done, result=4
[AutoRemoteSyscalls] syscall mmap
[Task] resuming execution of 226 with PTRACE_CONT tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] Used enter_syscall; status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] syscall exit status=0x857f (SYSCALL)
[AutoRemoteSyscalls] done, result=1879048192
[AutoRemoteSyscalls] syscall close
[Task] resuming execution of 226 with PTRACE_CONT tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] Used enter_syscall; status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] syscall exit status=0x857f (SYSCALL)
[AutoRemoteSyscalls] done, result=0
[AddressSpace] mmap(0x70000000, 4096, 0x5, 0x12, 0)
[AddressSpace] munmap(0x70000000, 4096)
[AddressSpace]   mapping at 0x55d267fd8000 out of range, done.
[AddressSpace]   mapping 0x70000000-0x70001000 r-xp 00000000 103:02 2237313    /codetracer/libs/rr/bin/rr_page_64
[AddressSpace]   no mappings to coalesce
[AutoRemoteSyscalls] syscall brk
[Task] resuming execution of 226 with PTRACE_CONT tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] Used enter_syscall; status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] syscall exit status=0x857f (SYSCALL)
[AutoRemoteSyscalls] done, result=94362198409216
[AutoRemoteSyscalls] syscall openat
[Task] resuming execution of 226 with PTRACE_CONT tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] Used enter_syscall; status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] syscall exit status=0x857f (SYSCALL)
[AutoRemoteSyscalls] done, result=4
[AutoRemoteSyscalls] syscall sendmsg
[Task] resuming execution of 226 with PTRACE_CONT tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] Used enter_syscall; status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] syscall exit status=0x857f (SYSCALL)
[AutoRemoteSyscalls] done, result=1
[Session] created shmem segment /tmp/rr-shared-preload_thread_locals-226-0
[AutoRemoteSyscalls] syscall mmap
[Task] resuming execution of 226 with PTRACE_CONT tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] Used enter_syscall; status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] syscall exit status=0x857f (SYSCALL)
[AutoRemoteSyscalls] done, result=1879052288
[AddressSpace] mmap(0x70001000, 104, 0x3, 0x11, 0)
[AddressSpace] munmap(0x70001000, 4096)
[AddressSpace]   mapping at 0x55d267fd8000 out of range, done.
[AddressSpace]   mapping 0x70001000-0x70002000 rw-s 00000000 00:40 8399809    /tmp/rr-shared-preload_thread_locals-226-0
[AddressSpace]   no mappings to coalesce
[AutoRemoteSyscalls] syscall close
[Task] resuming execution of 226 with PTRACE_CONT tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x7057f (PTRACE_EVENT_SECCOMP)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] Used enter_syscall; status=0x7057f (PTRACE_EVENT_SECCOMP)
[Task] resuming execution of 226 with PTRACE_SYSCALL tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x857f (SYSCALL)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] syscall exit status=0x857f (SYSCALL)
[AutoRemoteSyscalls] done, result=0
[AutoRemoteSyscalls] syscall arch_prctl
[Task] resuming execution of 226 with PTRACE_SINGLESTEP tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x57f (STOP-SIGTRAP)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] Used singlestep path; status=0x57f (STOP-SIGTRAP)
[AutoRemoteSyscalls] done, result=0
[AutoRemoteSyscalls] syscall munmap
[Task] resuming execution of 226 with PTRACE_SINGLESTEP tick_period -2
[Task] going into blocking waitpid(226) ...
[Task]   waitpid(226) returns 226; status 0x57f (STOP-SIGTRAP)
[Task]   (refreshing register cache)
[AutoRemoteSyscalls] Used singlestep path; status=0x57f (STOP-SIGTRAP)
[AutoRemoteSyscalls] done, result=0
[AddressSpace] munmap(0x7ffd84ffa000, 12288)
[AddressSpace] munmap(0x7ffd84ffa000, 12288)
[AddressSpace]   unmapping (0x7ffd84ffa000-0x7ffd84ffd000) ...
[AddressSpace]   erased (0x7ffd84ffa000-0x7ffd84ffd000 r--p 00000000 00:00 0          [vvar]) ...
[AutoRemoteSyscalls] syscall munmap
[Task] resuming execution of 226 with PTRACE_SINGLESTEP tick_period -2
[Task] going into blocking waitpid(226) ...
root@730c5ac69a38:/codetracer#

@alehander92
Copy link
Contributor Author

alehander92 commented Sep 17, 2019 via email

@khuey
Copy link
Collaborator

khuey commented Sep 17, 2019 •
edited
Loading

Can you attach gdb to rr itself (not to the tracee with the printed instructions) and get a stack trace?

@alehander92
Copy link
Contributor Author

using pidof ?

#0  0x00007f9e487d3eb7 in __libc_accept (fd=3, addr=..., len=0x0) at ../sysdeps/unix/sysv/linux/accept.c:26
#1  0x000055eebc9ece8f in rr::GdbConnection::await_debugger (this=0x55eebea28fe0, listen_fd=...) at ../src/GdbConnection.cc:71
#2  0x000055eebca08ac5 in rr::await_connection (t=0x55eebea27b70, listen_fd=..., features=...) at ../src/GdbServer.cc:1482
#3  0x000055eebca0a0e3 in rr::GdbServer::emergency_debug (t=0x55eebea27b70) at ../src/GdbServer.cc:1683
#4  0x000055eebca2fd00 in rr::emergency_debug (t=0x55eebea27b70) at ../src/log.cc:403
#5  0x000055eebca2ff5a in rr::EmergencyDebugOstream::~EmergencyDebugOstream (this=0x7fff62d5a910, __in_chrg=<optimized out>) at ../src/log.cc:425
#6  0x000055eebcad4880 in rr::RecordTask::record_remote (this=0x55eebea27b70, addr=..., num_bytes=-12288) at ../src/RecordTask.cc:1507
#7  0x000055eebca86eb9 in rr::process_execve (t=0x55eebea27b70, syscall_state=...) at ../src/record_syscall.cc:4625
#8  0x000055eebca9cf2e in rr::rec_process_syscall_arch<rr::X64Arch> (t=0x55eebea27b70, syscall_state=...) at ../src/record_syscall.cc:5196
#9  0x000055eebca8a45b in rr::rec_process_syscall_internal (t=0x55eebea27b70, arch=rr::x86_64, syscall_state=...) at ../src/record_syscall.cc:5635
#10 0x000055eebca8a546 in rr::rec_process_syscall (t=0x55eebea27b70) at ../src/record_syscall.cc:5649
#11 0x000055eebca6eaca in rr::RecordSession::syscall_state_changed (this=0x55eebea25a30, t=0x55eebea27b70, step_state=0x7fff62d5b60c) at ../src/RecordSession.cc:1014
#12 0x000055eebca73c84 in rr::RecordSession::record_step (this=0x55eebea25a30) at ../src/RecordSession.cc:2043
#13 0x000055eebca669dd in rr::record (args=std::vector of length 1, capacity 2 = {...}, flags=...) at ../src/RecordCommand.cc:606
#14 0x000055eebca674ad in rr::RecordCommand::run (this=0x55eebcd493d0 <rr::RecordCommand::singleton>, args=std::vector of length 1, capacity 2 = {...}) at ../src/RecordCommand.cc:729
#15 0x000055eebcb9e5eb in main (argc=3, argv=0x7fff62d5b9e8) at ../src/main.cc:268

@alehander92
Copy link
Contributor Author

i am not sure if this is the stacktrace sorry, is there another way to attach except attach pid (i guess you can't directly rr under rr )

@alehander92
Copy link
Contributor Author

(on the other hand, am i correct that if one somehow runs rr not as a child process, but connects on network with a wrapper around it, maybe at least one can record programs "using" rr? but this is offtopic for this issue)

@rocallahan
Copy link
Collaborator

This is the right stacktrace and it's helpful, thanks.

In gdb can you go up to frame #7 and print km and print st?

Also if you print t->tid to get the tracee process tid, then from a shell do cat /proc/<tid>/maps?

Thanks!

@alehander92
Copy link
Contributor Author

thank you: this is the output (i'll try to take a look at older versions, if it worked before, maybe something changed on my env)

(gdb) frame 7
#7  0x0000565415e38eb9 in rr::process_execve (t=0x56541669ab70, syscall_state=...) at ../src/record_syscall.cc:4625
4625	        t->record_remote(km.start(), min(end, (off64_t)km.size()));
(gdb) print km
$1 = (const rr::KernelMapping &) @0x56541669f370: {<rr::MemoryRange> = {start_ = {ptr = 94130003292160}, end_ = {ptr = 94130003369984}}, static map_flags_mask = 147747, static checkable_flags_mask = 3, 
  static NO_DEVICE = 0, static NO_INODE = 0, fsname_ = "/", device_ = 64, inode_ = 4985254, prot_ = 5, flags_ = 2, offset = 16384}
(gdb) print st
$2 = {st_dev = 64, st_ino = 13256016, st_nlink = 1, st_mode = 16877, st_uid = 0, st_gid = 0, __pad0 = 0, st_rdev = 0, st_size = 4096, st_blksize = 4096, st_blocks = 8, st_atim = {tv_sec = 1568893581, 
    tv_nsec = 422652950}, st_mtim = {tv_sec = 1568893581, tv_nsec = 422652950}, st_ctim = {tv_sec = 1568893588, tv_nsec = 470567127}, __glibc_reserved = {0, 0, 0}}
(gdb) print t->tid
$3 = 38
(gdb) quit
A debugging session is active.

	Inferior 1 [process 26] will be detached.

Quit anyway? (y or n) y
Detaching from program: /codetracer/libs/rr/bin/rr, process 26
[Inferior 1 (process 26) detached]
root@4221a6e5e48e:/codetracer# cat /proc/<tid>/maps
bash: tid: No such file or directory
root@4221a6e5e48e:/codetracer# cat /proc/38/maps
70000000-70001000 r-xp 00000000 103:02 2237313                           /codetracer/libs/rr/bin/rr_page_64
70001000-70002000 rw-s 00000000 103:02 13256097                          / (deleted)
559c59687000-559c5968b000 r--p 00000000 103:02 4985254                   /
559c5968b000-559c5969e000 r-xp 00004000 103:02 4985254                   /
559c5969e000-559c596a7000 r--p 00017000 103:02 4985254                   /
559c596a8000-559c596aa000 rw-p 00020000 103:02 4985254                   /
559c596aa000-559c596ab000 rw-p 00000000 00:00 0 
7f6ab78af000-7f6ab78b0000 r--p 00000000 103:02 5258735                   /
7f6ab78b0000-7f6ab78d1000 r-xp 00001000 103:02 5258735                   /
7f6ab78d1000-7f6ab78d9000 r--p 00022000 103:02 5258735                   /
7f6ab78d9000-7f6ab78db000 rw-p 00029000 103:02 5258735                   /
7f6ab78db000-7f6ab78dc000 rw-p 00000000 00:00 0 
7ffeab771000-7ffeab793000 rw-p 00000000 00:00 0                          [stack]
7ffeab7ab000-7ffeab7ac000 r-xp 00000000 00:00 0                          [vdso]
ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0                  [vsyscall]
root@4221a6e5e48e:/codetracer# cat /proc/<tid>/maps

@rocallahan
Copy link
Collaborator

That makes no sense whatsoever!!!

The kernel seems to be saying that the file that is being executed, and ld.so as well, are both ... the root directory.

Wild guess: maybe there is some kind of security module or something present that is deliberately hiding the results in /proc/.../maps. That would cause this issue in rr.

@alehander92
Copy link
Contributor Author

yes, this seems strange ! funny
so i shouldn't see / , i'll try to make this work

@alehander92
Copy link
Contributor Author

it seems that this /proc/id/maps problems doesnt' arise on a colleague machine, so probably something wrong with my setup

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@rocallahan @khuey @alehander92