strace cann't trace time() system call on x86_64

[Eugene Syromyatnikov]

On Fri, Oct 14, 2016 at 8:35 AM, ChenJingPiao <chenjingpiao at foxmail.com> wrote:
> Version:strace-4.14, strace-4.13, strace-4.5.20
> Environment: ubuntu 16.04.1 LTS x86_64
>
> I use strace to trace a program with time() system call,
> but it not print time() system call. I also do the same
> test on ubuntu 14.04 LTS i386, it can trace time() system call.
> I can find the time() system in strace-4.14/linux/x86_64/syscallent.h
> and strace-4.14/linux/dummy.h.
> So I think it may be a bug and report it.Thank you.
>
> test program: test.c
>
> #include <stdlib.h>
> #include <time.h>
> int main()
> {
> time_t t;
> t = time(NULL);
> return 0;
> }
>
> $strace -o output.txt ./test
>
> output.txt:
>
> execve("./a.out", ["./a.out"], [/* 72 vars */]) = 0
> brk(NULL)                               = 0xb5c000
> access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or
> directory)
> mmap(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
> 0x7f2284ddc000
> access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or
> directory)
> open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3
> fstat(3, {st_mode=S_IFREG|0644, st_size=112807, ...}) = 0
> mmap(NULL, 112807, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f2284dc0000
> close(3)                                = 0
> access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or
> directory)
> open("/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3
> read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0P\t\2\0\0\0\0\0"...,
> 832) = 832
> fstat(3, {st_mode=S_IFREG|0755, st_size=1864888, ...}) = 0
> mmap(NULL, 3967488, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) =
> 0x7f22847f0000
> mprotect(0x7f22849b0000, 2093056, PROT_NONE) = 0
> mmap(0x7f2284baf000, 24576, PROT_READ|PROT_WRITE,
> MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x1bf000) = 0x7f2284baf000
> mmap(0x7f2284bb5000, 14848, PROT_READ|PROT_WRITE,
> MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f2284bb5000
> close(3)                                = 0
> mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
> 0x7f2284dbf000
> mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
> 0x7f2284dbe000
> mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
> 0x7f2284dbd000
> arch_prctl(ARCH_SET_FS, 0x7f2284dbe700) = 0
> mprotect(0x7f2284baf000, 16384, PROT_READ) = 0
> mprotect(0x600000, 4096, PROT_READ)     = 0
> mprotect(0x7f2284dde000, 4096, PROT_READ) = 0
> munmap(0x7f2284dc0000, 112807)          = 0
> exit_group(0)                           = ?
> +++ exited with 0 +++
>
> $strace -e time ./test
> only print:
> +++ exited with 0 +++

This is due to the use of vDSO for getting current time, cpu and other
stuff. When call is performed via vDSO, no syscall performed and
ptrace doesn't stop tracee and doesn't notify strace. If you want to
trace time calls in existing code, you can try ltrace:

% ltrace ./a.out
__libc_start_main(0x40050c, 1, 0x7fff1da3a188, 0x400540, 0x400530
<unfinished ...>
time(NULL)

                                                        = 1476435165
+++ exited (status 0) +++

If you want to have time syscalls in code, you should call syscall directly():

% cat test.c
#include <stdlib.h>
#include <time.h>
#include <unistd.h>

#include <asm/unistd.h>

int main()
{
time_t t;
t = syscall(__NR_time, NULL);

return 0;
}
% gcc test.c
% strace -etime ./a.out
time(NULL)                              = 1476435223
+++ exited with 0 +++
%

The were options for turning vDSO/vsyscall off at runtime (in kernel),
but I do not see them in sysctl (except vsyscall32) on 3.16 kernel.
You can try vdso kernel parameter, though.

> This is my first time send email to mail list, if something wrong, please
> point it out.
> Thank you.
>
>
> ------------------------------------------------------------------------------
> Check out the vibrant tech community on one of the world's most
> engaging tech sites, SlashDot.org! http://sdm.link/slashdot
> _______________________________________________
> Strace-devel mailing list
> Strace-devel at lists.sourceforge.net
> https://lists.sourceforge.net/lists/listinfo/strace-devel
>



-- 
Eugene "eSyr" Syromyatnikov
mailto:evgSyr at gmail.com
xmpp:eSyr at jabber.{ru|org}