search

pmem / syscall_intercept

The system call intercepting library
Other
631 stars 116 forks source link

Test 25, 28 and 40 fail on Debian Jessie and Buster #77

Open elboulangero opened 6 years ago

elboulangero commented 6 years ago

The following tests fail on Debian Jessie (8) and Debian Buster (10). All tests pass on Debian Stretch (9).

The following tests FAILED:
     25 - fork_logging (Failed)
     28 - hook_clone (Failed)
     40 - syscall_format_logging (Failed)

Note that the failure in the last test could be related to the commit I submitted to fix the build https://github.com/pmem/syscall_intercept/commit/bb10939828b85563bf3eb1e75883d12bba447069

However this test already failed on Debian Buster before this commit, so... Maybe not related.

marcinslusarz commented 6 years ago

ctest --output-on-failure will tell you why it failed.

GBuella commented 6 years ago

https://github.com/pmem/syscall_intercept/pull/78

@elboulangero Could you try this branch: https://github.com/GBuella/syscall_intercept/tree/syscall_format_fix

I'm still interested in what ctest --output-on-failure says about the other two, fork_logging and hook_clone.

elboulangero commented 6 years ago

Hi @GBuella,

here comes more details of build and test on Debian Jessie.

I've been using your branch syscall_format_fix, and the test number 40 succeeds now.

# gcc --version
gcc (Debian 4.9.2-10) 4.9.2
# dpkg -l | grep "libc-dev"
ii  libc-dev-bin                   2.19-18+deb8u10
ii  linux-libc-dev:amd64           3.16.51-2
# mkdir _build && cd _build
# cmake ..
# make
# ctest --output-on-failure
      Start 25: fork_logging
25/40 Test #25: fork_logging ...........................***Failed    0.19 sec
Executing: LD_PRELOAD=/usr/src/syscall_intercept.gbuella/_build/libsyscall_intercept.so.0.1.0
        INTERCEPT_ALL_OBJS=1
        /usr/src/syscall_intercept.gbuella/_build/test/fork_logging /usr/src/syscall_intercept.gbuella/test/fork_logging.c .log.logging .log.2.logging
//*/*

Done being busy here
//*/*

Done being busy here
[MATCHING FAILED, COMPLETE FILE (.log.logging) BELOW]
/lib/x86_64-linux-gnu/libc.so.6 0xba012 -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), 0x00007feaf84949d0, 0x0) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xba012 -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), 0x00007feaf84949d0, 0x0) = 27187
/lib/x86_64-linux-gnu/libc.so.6 0xb9ab0 -- wait4(-1, 0x0, 0x0, 0x0) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xba012 -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), 0x00007feaf84949d0, 0x0) = 0
/lib/x86_64-linux-gnu/libc.so.6 0xb9ab0 -- wait4(-1, 0x0, 0x0, 0x0) = 27187
/lib/x86_64-linux-gnu/libc.so.6 0xdb95e -- open("/usr/src/syscall_intercept.gbuella/test/fork_logging.c", O_RDONLY) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdb95e -- open("/usr/src/syscall_intercept.gbuella/test/fork_logging.c", O_RDONLY) = 5
/lib/x86_64-linux-gnu/libc.so.6 0xdb512 -- fstat(5, 0x00007ffc86d25910) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdb512 -- fstat(5, 0x00007ffc86d25910) = 0
/lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = 0x00007feaf8498000
/lib/x86_64-linux-gnu/libc.so.6 0xdbb9e -- read(5, 0x00007feaf8498000, 4096) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdbb9e -- read(5, "/*\n * Copyright 2016-2017, Intel Corporation\n *\n * Redistribution and use in source and binary forms, with or without\n...", 4096) = 2828
/lib/x86_64-linux-gnu/libc.so.6 0xdb512 -- fstat(1, 0x00007ffc86d258f0) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdb512 -- fstat(1, 0x00007ffc86d258f0) = 0
/lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = 0x00007feaf8497000
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "/", 1) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "/", 1) = 1
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "/*", 2) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "/*", 2) = 2
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "/*\n", 3) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "/*\n", 3) = 3
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "\n", 1) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "\n", 1) = 1
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "Done being busy here\n", 21) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "Done being busy here\n", 21) = 21
/lib/x86_64-linux-gnu/libc.so.6 0xdc1be -- close(5) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdc1be -- close(5) = 0
/lib/x86_64-linux-gnu/libc.so.6 0xe4755 -- munmap(0x00007feaf8498000, 0x1000) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xe4755 -- munmap(0x00007feaf8498000, 0x1000) = 0

[EOF]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:1   $(S) $(XX) -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), $(XX), $(XX)) = ?
.log.logging:1         /lib/x86_64-linux-gnu/libc.so.6 0xba012 -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), 0x00007feaf84949d0, 0x0) = ?
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:2   $(OPT)$(S) $(XX) -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), $(XX), $(XX)) = 0
.log.logging:2         /lib/x86_64-linux-gnu/libc.so.6 0xba012 -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), 0x00007feaf84949d0, 0x0) = 27187
.log.logging:2        [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:3   $(S) $(XX) -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), $(XX), $(XX)) = $(N)
.log.logging:2         /lib/x86_64-linux-gnu/libc.so.6 0xba012 -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), 0x00007feaf84949d0, 0x0) = 27187
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:4   $(OPT)$(S) $(XX) -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), $(XX), $(XX)) = 0
.log.logging:3         /lib/x86_64-linux-gnu/libc.so.6 0xb9ab0 -- wait4(-1, 0x0, 0x0, 0x0) = ?
.log.logging:3        [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:5   $(S) $(XX) -- wait4(-1, 0x0, 0x0, 0x0) = ?
.log.logging:3         /lib/x86_64-linux-gnu/libc.so.6 0xb9ab0 -- wait4(-1, 0x0, 0x0, 0x0) = ?
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:6   $(OPT)$(S) $(XX) -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), $(XX), $(XX)) = 0
.log.logging:4         /lib/x86_64-linux-gnu/libc.so.6 0xba012 -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), 0x00007feaf84949d0, 0x0) = 0
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:7   $(OPT)$(S) $(XX) -- set_robust_list($(XX), $(N)) = ?
.log.logging:5         /lib/x86_64-linux-gnu/libc.so.6 0xb9ab0 -- wait4(-1, 0x0, 0x0, 0x0) = 27187
.log.logging:5        [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:8   $(OPT)$(S) $(XX) -- set_robust_list($(XX), $(N)) = $(N)
.log.logging:5         /lib/x86_64-linux-gnu/libc.so.6 0xb9ab0 -- wait4(-1, 0x0, 0x0, 0x0) = 27187
.log.logging:5        [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:9   $(S) $(XX) -- wait4(-1, 0x0, 0x0, 0x0) = $(N)
.log.logging:5         /lib/x86_64-linux-gnu/libc.so.6 0xb9ab0 -- wait4(-1, 0x0, 0x0, 0x0) = 27187
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:10  $(OPT)$(S) $(XX) -- open($(S), O_RDONLY) = ?
.log.logging:6         /lib/x86_64-linux-gnu/libc.so.6 0xdb95e -- open("/usr/src/syscall_intercept.gbuella/test/fork_logging.c", O_RDONLY) = ?
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:11  $(OPT)$(S) $(XX) -- open($(S), O_RDONLY) = $(N)
.log.logging:7         /lib/x86_64-linux-gnu/libc.so.6 0xdb95e -- open("/usr/src/syscall_intercept.gbuella/test/fork_logging.c", O_RDONLY) = 5
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:12  $(OPT)$(S) $(XX) -- openat(AT_FDCWD, $(S), O_RDONLY) = ?
.log.logging:8         /lib/x86_64-linux-gnu/libc.so.6 0xdb512 -- fstat(5, 0x00007ffc86d25910) = ?
.log.logging:8        [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:13  $(OPT)$(S) $(XX) -- openat(AT_FDCWD, $(S), O_RDONLY) = $(N)
.log.logging:8         /lib/x86_64-linux-gnu/libc.so.6 0xdb512 -- fstat(5, 0x00007ffc86d25910) = ?
.log.logging:8        [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:14  $(S) $(XX) -- fstat($(N), $(XX)) = ?
.log.logging:8         /lib/x86_64-linux-gnu/libc.so.6 0xdb512 -- fstat(5, 0x00007ffc86d25910) = ?
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:15  $(S) $(XX) -- fstat($(N), $(XX)) = 0
.log.logging:9         /lib/x86_64-linux-gnu/libc.so.6 0xdb512 -- fstat(5, 0x00007ffc86d25910) = 0
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:16  $(OPT)$(S) $(XX) -- mmap($(XX), $(N), $(N), $(N), $(N), $(XX)) = ?
.log.logging:10        /lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = ?
.log.logging:10       [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:17  $(OPT)$(S) $(XX) -- mmap($(XX), $(N), $(N), $(N), $(N), $(XX)) = $(N)
.log.logging:10        /lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = ?
.log.logging:10       [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:18  $(OPT)$(S) $(XX) -- mmap($(XX), $(N), $(N), $(N), $(N), $(XX)) = ?
.log.logging:10        /lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = ?
.log.logging:10       [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:19  $(OPT)$(S) $(XX) -- mmap($(XX), $(N), $(N), $(N), $(N), $(XX)) = $(N)
.log.logging:10        /lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = ?
.log.logging:10       [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:20  $(S) $(XX) -- read($(N), $(XX), $(N)) = ?
.log.logging:10        /lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = ?
FAIL: match.pl: /usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:20 did not match pattern
CMake Error at /usr/src/syscall_intercept.gbuella/test/check_log.cmake:82 (message):
  Log does not match! 255
      Start 28: hook_clone
28/40 Test #28: hook_clone .............................***Failed    0.17 sec
Executing: LD_PRELOAD=/usr/src/syscall_intercept.gbuella/_build/test/libhook_test_clone_preload.so
        INTERCEPT_ALL_OBJS=1
        /usr/src/syscall_intercept.gbuella/_build/test/fork_logging /usr/src/syscall_intercept.gbuella/test/fork_logging.c .log.hook_clone .log.2.hook_clone
//*/*

Done being busy here
//*/*

Done being busy here
[MATCHING FAILED, COMPLETE FILE (.log.hook_clone) BELOW]
/lib/x86_64-linux-gnu/libc.so.6 0xba012 -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), 0x00007f66c2b549d0, 0x0) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xba012 -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), 0x00007f66c2b549d0, 0x0) = 27201
/lib/x86_64-linux-gnu/libc.so.6 0xb9ab0 -- wait4(-1, 0x0, 0x0, 0x0) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xba012 -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), 0x00007f66c2b549d0, 0x0) = 0
/lib/x86_64-linux-gnu/libc.so.6 0xb9ab0 -- wait4(-1, 0x0, 0x0, 0x0) = 27201
/lib/x86_64-linux-gnu/libc.so.6 0xdb95e -- open("/usr/src/syscall_intercept.gbuella/test/fork_logging.c", O_RDONLY) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdb95e -- open("/usr/src/syscall_intercept.gbuella/test/fork_logging.c", O_RDONLY) = 5
/lib/x86_64-linux-gnu/libc.so.6 0xdb512 -- fstat(5, 0x00007ffee181e3d0) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdb512 -- fstat(5, 0x00007ffee181e3d0) = 0
/lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = 0x00007f66c2b57000
/lib/x86_64-linux-gnu/libc.so.6 0xdbb9e -- read(5, 0x00007f66c2b57000, 4096) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdbb9e -- read(5, "/*\n * Copyright 2016-2017, Intel Corporation\n *\n * Redistribution and use in source and binary forms, with or without\n...", 4096) = 2828
/lib/x86_64-linux-gnu/libc.so.6 0xdb512 -- fstat(1, 0x00007ffee181e3b0) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdb512 -- fstat(1, 0x00007ffee181e3b0) = 0
/lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = 0x00007f66c2aca000
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "/", 1) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "/", 1) = 1
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "/*", 2) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "/*", 2) = 2
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "/*\n", 3) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "/*\n", 3) = 3
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "\n", 1) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "\n", 1) = 1
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "Done being busy here\n", 21) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdbbfe -- write(1, "Done being busy here\n", 21) = 21
/lib/x86_64-linux-gnu/libc.so.6 0xdc1be -- close(5) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xdc1be -- close(5) = 0
/lib/x86_64-linux-gnu/libc.so.6 0xe4755 -- munmap(0x00007f66c2b57000, 0x1000) = ?
/lib/x86_64-linux-gnu/libc.so.6 0xe4755 -- munmap(0x00007f66c2b57000, 0x1000) = 0

[EOF]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:1   $(S) $(XX) -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), $(XX), $(XX)) = ?
.log.hook_clone:1         /lib/x86_64-linux-gnu/libc.so.6 0xba012 -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), 0x00007f66c2b549d0, 0x0) = ?
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:2   $(OPT)$(S) $(XX) -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), $(XX), $(XX)) = 0
.log.hook_clone:2         /lib/x86_64-linux-gnu/libc.so.6 0xba012 -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), 0x00007f66c2b549d0, 0x0) = 27201
.log.hook_clone:2        [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:3   $(S) $(XX) -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), $(XX), $(XX)) = $(N)
.log.hook_clone:2         /lib/x86_64-linux-gnu/libc.so.6 0xba012 -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), 0x00007f66c2b549d0, 0x0) = 27201
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:4   $(OPT)$(S) $(XX) -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), $(XX), $(XX)) = 0
.log.hook_clone:3         /lib/x86_64-linux-gnu/libc.so.6 0xb9ab0 -- wait4(-1, 0x0, 0x0, 0x0) = ?
.log.hook_clone:3        [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:5   $(S) $(XX) -- wait4(-1, 0x0, 0x0, 0x0) = ?
.log.hook_clone:3         /lib/x86_64-linux-gnu/libc.so.6 0xb9ab0 -- wait4(-1, 0x0, 0x0, 0x0) = ?
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:6   $(OPT)$(S) $(XX) -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), $(XX), $(XX)) = 0
.log.hook_clone:4         /lib/x86_64-linux-gnu/libc.so.6 0xba012 -- clone(CLONE_CHILD_CLEARTID | CLONE_CHILD_SETTID | 0x11, (null), (null), 0x00007f66c2b549d0, 0x0) = 0
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:7   $(OPT)$(S) $(XX) -- set_robust_list($(XX), $(N)) = ?
.log.hook_clone:5         /lib/x86_64-linux-gnu/libc.so.6 0xb9ab0 -- wait4(-1, 0x0, 0x0, 0x0) = 27201
.log.hook_clone:5        [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:8   $(OPT)$(S) $(XX) -- set_robust_list($(XX), $(N)) = $(N)
.log.hook_clone:5         /lib/x86_64-linux-gnu/libc.so.6 0xb9ab0 -- wait4(-1, 0x0, 0x0, 0x0) = 27201
.log.hook_clone:5        [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:9   $(S) $(XX) -- wait4(-1, 0x0, 0x0, 0x0) = $(N)
.log.hook_clone:5         /lib/x86_64-linux-gnu/libc.so.6 0xb9ab0 -- wait4(-1, 0x0, 0x0, 0x0) = 27201
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:10  $(OPT)$(S) $(XX) -- open($(S), O_RDONLY) = ?
.log.hook_clone:6         /lib/x86_64-linux-gnu/libc.so.6 0xdb95e -- open("/usr/src/syscall_intercept.gbuella/test/fork_logging.c", O_RDONLY) = ?
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:11  $(OPT)$(S) $(XX) -- open($(S), O_RDONLY) = $(N)
.log.hook_clone:7         /lib/x86_64-linux-gnu/libc.so.6 0xdb95e -- open("/usr/src/syscall_intercept.gbuella/test/fork_logging.c", O_RDONLY) = 5
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:12  $(OPT)$(S) $(XX) -- openat(AT_FDCWD, $(S), O_RDONLY) = ?
.log.hook_clone:8         /lib/x86_64-linux-gnu/libc.so.6 0xdb512 -- fstat(5, 0x00007ffee181e3d0) = ?
.log.hook_clone:8        [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:13  $(OPT)$(S) $(XX) -- openat(AT_FDCWD, $(S), O_RDONLY) = $(N)
.log.hook_clone:8         /lib/x86_64-linux-gnu/libc.so.6 0xdb512 -- fstat(5, 0x00007ffee181e3d0) = ?
.log.hook_clone:8        [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:14  $(S) $(XX) -- fstat($(N), $(XX)) = ?
.log.hook_clone:8         /lib/x86_64-linux-gnu/libc.so.6 0xdb512 -- fstat(5, 0x00007ffee181e3d0) = ?
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:15  $(S) $(XX) -- fstat($(N), $(XX)) = 0
.log.hook_clone:9         /lib/x86_64-linux-gnu/libc.so.6 0xdb512 -- fstat(5, 0x00007ffee181e3d0) = 0
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:16  $(OPT)$(S) $(XX) -- mmap($(XX), $(N), $(N), $(N), $(N), $(XX)) = ?
.log.hook_clone:10        /lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = ?
.log.hook_clone:10       [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:17  $(OPT)$(S) $(XX) -- mmap($(XX), $(N), $(N), $(N), $(N), $(XX)) = $(N)
.log.hook_clone:10        /lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = ?
.log.hook_clone:10       [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:18  $(OPT)$(S) $(XX) -- mmap($(XX), $(N), $(N), $(N), $(N), $(XX)) = ?
.log.hook_clone:10        /lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = ?
.log.hook_clone:10       [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:19  $(OPT)$(S) $(XX) -- mmap($(XX), $(N), $(N), $(N), $(N), $(XX)) = $(N)
.log.hook_clone:10        /lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = ?
.log.hook_clone:10       [skipping optional line]
/usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:20  $(S) $(XX) -- read($(N), $(XX), $(N)) = ?
.log.hook_clone:10        /lib/x86_64-linux-gnu/libc.so.6 0xe4728 -- mmap((null), 0x1000, 0x3, 0x22, -1, 0x0) = ?
FAIL: match.pl: /usr/src/syscall_intercept.gbuella/test/libcintercept0.log.match:20 did not match pattern
CMake Error at /usr/src/syscall_intercept.gbuella/test/check_log.cmake:82 (message):
  Log does not match! 255
GBuella commented 6 years ago

I guess the matching script doesn't match "(null)" with "$(XX)". We could add such lines to the match files as a quickfix for now: $(OPT)$(S) $(XX) -- mmap((null), $(N), $(N), $(N), $(N), $(XX)) = ?

marcinslusarz commented 6 years ago

I think we should replace $(XX) with (null) wherever we expect null address.

Some time ago we used to print 0x0 instead of (null) for null pointers (see commit description of 2db5fa083da0d8cce0e4651725cb4dbb0d944ba8 as an example). On newer distros there are no mmap calls in this workload, so we haven't noticed that in conversion to (null).