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.

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

Add support for readlinkat syscall #1579

Closed
wants to merge 1 commit into from

Conversation

janisozaur
Copy link
Contributor

I based most of the code on readlink syscall already there. The test is by no means exhaustive, but passes.

Can you please comment if there's more testing needed?

This does not solve #1578 completely for me, but at least takes me a bit further and the error looks unrelated:

rr: Saving the execution of `./sdl-test' to trace directory `/home/janisozaur/.rr/sdl-test-7'.
[FATAL /home/janisozaur/workspace/rr/src/record_syscall.cc:3057:rec_process_syscall_arch() errno: 0 'Success'] 
 (task 17746 (rec:17746) at time 2636)
 ->  Assertion `t->regs().syscall_result_signed() == -syscall_state.expect_errno' failed to hold. Expected EINVAL for 'ioctl' but got result 0; Unknown ioctl(0x80106463): type:0x64 nr:0x63 dir:0x2 size:16 addr:0xffe9371c
(gdb) bt
#0  0x70000018 in ?? ()
#1  0xf7786167 in _traced_raw_syscall () at /home/janisozaur/workspace/rr/build/32/traced_syscall_shared.S:38
#2  0xf7783b95 in traced_raw_syscall (call=call@entry=0xffe93688) at /home/janisozaur/workspace/rr/build/32/preload.c:312
#3  0xf7784d97 in syscall_hook_internal (call=0xffe93688) at /home/janisozaur/workspace/rr/build/32/preload.c:2021
#4  syscall_hook (call=0xffe93688) at /home/janisozaur/workspace/rr/build/32/preload.c:2029
#5  0xf77861b2 in _syscall_hook_trampoline () at /home/janisozaur/workspace/rr/build/32/syscall_hook.S:59
#6  0xf734f479 in ioctl () from /usr/lib32/libc.so.6
#7  0xf6dbd67e in drmIoctl () from /usr/lib32/libdrm.so.2
#8  0xf66f3143 in drm_intel_bufmgr_gem_init () from /usr/lib32/libdrm_intel.so.1
#9  0xf6b29805 in ?? () from /usr/lib32/xorg/modules/dri/i965_dri.so
#10 0xf69f959a in ?? () from /usr/lib32/xorg/modules/dri/i965_dri.so
#11 0xf6eb8bf1 in ?? () from /usr/lib32/libGL.so.1
#12 0xf6e8d050 in ?? () from /usr/lib32/libGL.so.1
#13 0xf6e8904e in ?? () from /usr/lib32/libGL.so.1
#14 0xf6e891f2 in glXChooseVisual () from /usr/lib32/libGL.so.1
#15 0xf76e2af5 in X11_GL_GetVisual (_this=0x82d0b90, display=0x82d12b8, screen=0) at /tmp/packerbuild-1000/lib32-sdl2/lib32-sdl2/src/SDL2-2.0.3/src/video/x11/SDL_x11opengl.c:525
#16 0xf76e2d50 in X11_GL_InitExtensions (_this=0x82d0b90) at /tmp/packerbuild-1000/lib32-sdl2/lib32-sdl2/src/SDL2-2.0.3/src/video/x11/SDL_x11opengl.c:323
#17 X11_GL_LoadLibrary (_this=0x82d0b90, path=<optimized out>) at /tmp/packerbuild-1000/lib32-sdl2/lib32-sdl2/src/SDL2-2.0.3/src/video/x11/SDL_x11opengl.c:218
#18 0xf76d5e70 in SDL_GL_LoadLibrary_REAL (path=0x0) at /tmp/packerbuild-1000/lib32-sdl2/lib32-sdl2/src/SDL2-2.0.3/src/video/SDL_video.c:2401
#19 0xf76d7e06 in SDL_CreateWindow_REAL (title=0xf76fb9b2 "OpenGL test", x=-32, y=-32, w=32, h=32, flags=10) at /tmp/packerbuild-1000/lib32-sdl2/lib32-sdl2/src/SDL2-2.0.3/src/video/SDL_video.c:1240
#20 0xf76d7aab in ShouldUseTextureFramebuffer () at /tmp/packerbuild-1000/lib32-sdl2/lib32-sdl2/src/SDL2-2.0.3/src/video/SDL_video.c:192
#21 SDL_VideoInit_REAL (driver_name=<optimized out>) at /tmp/packerbuild-1000/lib32-sdl2/lib32-sdl2/src/SDL2-2.0.3/src/video/SDL_video.c:506
#22 0xf762f6aa in SDL_InitSubSystem_REAL (flags=16416) at /tmp/packerbuild-1000/lib32-sdl2/lib32-sdl2/src/SDL2-2.0.3/src/SDL.c:173
#23 0xf765ea11 in SDL_Init_DEFAULT (a=32) at /tmp/packerbuild-1000/lib32-sdl2/lib32-sdl2/src/SDL2-2.0.3/src/dynapi/SDL_dynapi_procs.h:89
#24 0xf765ed47 in SDL_Init (a=32) at /tmp/packerbuild-1000/lib32-sdl2/lib32-sdl2/src/SDL2-2.0.3/src/dynapi/SDL_dynapi_procs.h:89
#25 0x0804941f in main ()

@janisozaur
Copy link
Contributor Author

I ran whole test suite with ctest:

99% tests passed, 2 tests failed out of 1360

Total Test time (real) = 1560.84 sec

The following tests FAILED:
    983 - sigreturn-32 (Failed)
    984 - sigreturn-32-no-syscallbuf (Failed)
Errors while running CTest

Both of the highlighted tests fail also on vanilla master:

test 979
    Start 979: sigreturn-32

979: Test command: /usr/bin/bash "/home/janisozaur/workspace/rr/src/test/basic_test.run" "-b" "/home/janisozaur/workspace/rr" "/home/janisozaur/workspace/rr/build" "sigreturn_32"
979: Test timeout computed to be: 9.99988e+06
979: Test 'sigreturn_32' FAILED: : error during recording:
979: --------------------------------------------------
979: sigreturn_32-9AbsQJwYW: /home/janisozaur/workspace/rr/build/32/sigreturn.c:151: main: Assertion `"FAILED: !" && check_cond("XMM register should have been preserved" && memcmp(xmm, xmm_good, sizeof(xmm)) == 0)' failed.
979: --------------------------------------------------
979: record.out:
979: --------------------------------------------------
979: xmm 0 incoming: 0 0 0 0
979: FAILED: errno=0 (Success)
979: --------------------------------------------------
979: Test sigreturn_32 failed, leaving behind /tmp/rr-test-sigreturn_32-9AbsQJwYW
979: To replay the failed test, run
979:   _RR_TRACE_DIR=/tmp/rr-test-sigreturn_32-9AbsQJwYW rr replay
1/4 Test #979: sigreturn-32 .......................***Failed  Error regular expression found in output. Regex=[FAILED]  0.21 sec
test 980
    Start 980: sigreturn-32-no-syscallbuf

980: Test command: /usr/bin/bash "/home/janisozaur/workspace/rr/src/test/basic_test.run" "-n" "/home/janisozaur/workspace/rr" "/home/janisozaur/workspace/rr/build" "sigreturn_32"
980: Test timeout computed to be: 9.99988e+06
980: Test 'sigreturn_32' FAILED: : error during recording:
980: --------------------------------------------------
980: sigreturn_32-rzpxAUbjV: /home/janisozaur/workspace/rr/build/32/sigreturn.c:151: main: Assertion `"FAILED: !" && check_cond("XMM register should have been preserved" && memcmp(xmm, xmm_good, sizeof(xmm)) == 0)' failed.
980: --------------------------------------------------
980: record.out:
980: --------------------------------------------------
980: xmm 0 incoming: 0 0 0 0
980: FAILED: errno=0 (Success)
980: --------------------------------------------------
980: Test sigreturn_32 failed, leaving behind /tmp/rr-test-sigreturn_32-rzpxAUbjV
980: To replay the failed test, run
980:   _RR_TRACE_DIR=/tmp/rr-test-sigreturn_32-rzpxAUbjV rr replay


ret = untraced_syscall4(syscallno, dirfd, path, buf2, bufsiz);
ptr = copy_output_buffer(ret, ptr, buf, buf2);
return commit_raw_syscall(syscallno, ptr, ret);
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We don't need syscall buffering support unless some real workload does a lot of readlinkat calls, e.g. more than a thousand.

@rocallahan
Copy link
Collaborator

Merged with those changes: e64e82e

@rocallahan rocallahan closed this Nov 5, 2015
@janisozaur
Copy link
Contributor Author

thank you

@rocallahan
Copy link
Collaborator

The next issue you're hitting is a DRM-related ioctl. We don't support those in rr currently. rr tries to block access to /dev/dri/*, which is normally enough to avoid DRI and trigger fallback to llvmpipe. I'm not sure why that's not working in your case. strace should tell you how this fd got opened and suggest how we can block it in rr. Anyway, please open another issue for that.

[Another option would be to actually support the DRM ioctls in rr, but that's a significantly bigger project and depending on how the kernel/user interface works, may not even be possible. In particular if the kernel/driver writes to memory that's read from user space with no intervening synchronizing operations visible to rr (i.e. a syscall), it won't work.]

@janisozaur
Copy link
Contributor Author

I'm not sure why /dev/dri access was not blocked and strace produces an overwhelming amount of logs and eventually fails to start the test case.

I used strace -ff -o sdl-test-strace ../rr/build/bin/rr ./sdl-test to start it, but none of the created log files show up when doing grep -rni dri sdl-test-strace*. The error I get is:

[FATAL /home/janisozaur/workspace/rr/src/task.cc:3101:spawn() errno: 1 'Operation not permitted'] 
 -> PTRACE_SEIZE failed for tid 7129

Is there something I could do here?

However, now that you mentioned there should be a fallback to llvmpipe, I tested sdl-test with LIBGL_ALWAYS_SOFTWARE=1 ./sdl-test and since that worked, I used rr to trace it, succesfully. I have also tested it on my real target and confirm it works.

@rocallahan
Copy link
Collaborator

Don't strace rr-running-your-application, just strace your application directly without rr.

@froydnj
Copy link
Contributor

froydnj commented Nov 5, 2015

You can also use strace -e open to limit the tracing to just the open(2) syscall.

@janisozaur
Copy link
Contributor Author

full strace is here: http://fpaste.org/287429/

Could it be that I created this problem myself now? Starting at line 1253:

readlinkat(AT_FDCWD, "/sys/dev/char/226:0", "../../devices/pci0000:00/0000:00"..., 99) = 47
lstat64("/sys", {st_mode=S_IFDIR|0555, st_size=0, ...}) = 0
lstat64("/sys/dev", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
lstat64("/sys/dev/char", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
lstat64("/sys/devices", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
lstat64("/sys/devices/pci0000:00", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
lstat64("/sys/devices/pci0000:00/0000:00:02.0", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
lstat64("/sys/devices/pci0000:00/0000:00:02.0/drm", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
lstat64("/sys/devices/pci0000:00/0000:00:02.0/drm/card0", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
access("/sys/devices/pci0000:00/0000:00:02.0/drm/card0/uevent", F_OK) = 0

From original report, it previously failed in this manner:

[FATAL /tmp/packerbuild-1000/rr/rr/src/rr-4.0.1/src/record_syscall.cc:3046:rec_process_syscall_arch() errno: 0 'Success'] 
 (task 23291 (rec:23291) at time 2432)
 ->  Assertion `t->regs().syscall_result_signed() == -syscall_state.expect_errno' failed to hold. Expected ENOSYS for 'readlinkat' but got result 47; execution of syscall unsupported by rr

@rocallahan
Copy link
Collaborator

recvmsg(3, {msg_name(0)=NULL, msg_iov(1)=[{"\1\1R\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0", 4096}], msg_controllen=16, [{cmsg_len=16, cmsg_level=SOL_SOCKET, cmsg_type=SCM_RIGHTS, [5]}], msg_flags=0}, 0) = 32

That's where we get the file descriptor that we subsequently do ioctls on, so no wonder it wasn't blocked. It's coming over the X socket so we don't really want to monkey with that.

There are a few things we can try here:

  • Block loading libdrm.so.* by adding code to is_blacklisted_filename in preload_interface.h.
  • Block loading libdrm_*.so.* the same way.
  • Block access to /sys/devices/*/drm/ in a similar way.
  • Make the first ioctl DRM_IOCTL_I915_GEM_GET_APERTURE fail by modifying prepare_ioctl to do syscall_state.emulate_result(-ENOSYS) or something like that.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants