Saturday, 26 April 2014

Tracing a program

Suppose some program on your system refuses to work or it works, but much slower then you've expected.  One way is to use strace program to follow system calls performed by given process.

 Use of strace

Commonly to use strace you should give the following command:
strace -o strace.out -ff touch /tmp/file

Here 

  • -o strace.out option means that strace program will output all information to the file named strace.out;
  • -ff means to strace the forked children of the program. Child straces outputs will be placed to strace.out.PID files, where PID is a pid of the child. If you want all the output to a single file, use -f argument instead (i.e. single f not double).
  • touch /tmp/file is the program with arguments which is to be straced.

 Strace results

So this is what we have in strace.out:
execve("/usr/bin/touch", ["touch", "/tmp/file"], [/* 51 vars */]) = 0
uname({sys="Linux", node="dhcp0-138", ...}) = 0
brk(0)                                  = 0x804f000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
fstat64(3, {st_mode=S_IFREG|0644, st_size=47843, ...}) = 0
mmap2(NULL, 47843, PROT_READ, MAP_PRIVATE, 3, 0) = 0xb7f1a000
close(3)                                = 0
open("/lib/libc.so.6", O_RDONLY)        = 3
read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\360V\1"..., 512) = 512
fstat64(3, {st_mode=S_IFREG|0755, st_size=1227872, ...}) = 0
mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f19000
mmap2(NULL, 1142148, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7e02000
mmap2(0xb7f13000, 16384, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x110) = 0xb7f13000
mmap2(0xb7f17000, 7556, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb7f17000
close(3)                                = 0
mprotect(0xb7f13000, 4096, PROT_READ)   = 0
munmap(0xb7f1a000, 47843)               = 0
open("/dev/urandom", O_RDONLY)          = 3
read(3, "v\0265\313", 4)                = 4
close(3)                                = 0
brk(0)                                  = 0x804f000
brk(0x8070000)                          = 0x8070000
open("/tmp/file", O_WRONLY|O_NONBLOCK|O_CREAT|O_NOCTTY|O_LARGEFILE, 0666) = -1 EACCES (Permission denied)
utime("/tmp/file", NULL)                = -1 EACCES (Permission denied)
write(2, "touch: ", 7)                  = 7
write(2, "cannot touch `/tmp/file\'", 24) = 24
write(2, ": Permission denied", 19)     = 19
write(2, "\n", 1)                       = 1
exit_group(1)                           = ?



In this case we see, that the problem is in access to /tmp/file:


open("/tmp/file", O_WRONLY|O_NONBLOCK|O_CREAT|O_NOCTTY|O_LARGEFILE, 0666) = -1 EACCES (Permission denied)
utime("/tmp/file", NULL)                = -1 EACCES (Permission denied)

No comments:

Post a Comment