Describing `strace` command output

Question

I have php process which could not finish for more then 2 days.

root     26511  0.0  1.6 407788 27684 ?        Ss   Jul09   0:08 /usr/bin/php action.php

This is the output from the strace command:

poll([{fd=7, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 1000) = 0 (Timeout)
poll([{fd=7, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout)
clock_gettime(CLOCK_MONOTONIC, {5533745, 664851437}) = 0
clock_gettime(CLOCK_MONOTONIC, {5533745, 664940247}) = 0
clock_gettime(CLOCK_MONOTONIC, {5533745, 665211013}) = 0
poll([{fd=7, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 1000) = 0 (Timeout)
poll([{fd=7, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout)
clock_gettime(CLOCK_MONOTONIC, {5533746, 666594416}) = 0
clock_gettime(CLOCK_MONOTONIC, {5533746, 666684149}) = 0
clock_gettime(CLOCK_MONOTONIC, {5533746, 666772214}) = 0
poll([{fd=7, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 1000) = 0 (Timeout)
poll([{fd=7, events=POLLIN|POLLPRI|POLLRDNORM|POLLRDBAND}], 1, 0) = 0 (Timeout)
clock_gettime(CLOCK_MONOTONIC, {5533747, 668356163}) = 0
clock_gettime(CLOCK_MONOTONIC, {5533747, 668447565}) = 0
clock_gettime(CLOCK_MONOTONIC, {5533747, 668538577}) = 0

Can you explain me what this output meaning? Or maybe I can get more informations about the stack process using some other command.

PHP version: PHP 5.4.30 CentOS release 6.5

You might find `ltrace` more helpful -- it traces library rather than system calls, giving you a higher-level insight into what's happening. — Flup, Jul 11 '14 at 08:49
@Flup There is an empty output from ltrace, is there some specific usage? I only use `ltrace -p 12345` — ibedelovski, Jul 11 '14 at 09:02

HBruijn · Accepted Answer · 2014-07-11T10:49:15.427

The strace command lists the systemcalls the application make as it is running.

If you're not de developer: Section 2 of the system manual documents systemcalls helping you understand what is happening.

man 2 poll

DESCRIPTION
   poll()  performs a similar task to select(2): it waits for one of a set
   of file descriptors to become ready to perform I/O.

The events requested in the poll system call are all read related on file descriptor 7, again from the manual page the events your application is requesting are:

POLLIN     There is data to read.
POLLPRI    There is urgent data to read. 
POLLRDNORM Equivalent to POLLIN.
POLLRDBAND Priority band data  can  be  read  (generally  unused  on Linux).

The strace lines show the poll action times out, the file descriptor (#7) doesn't become ready for read IO.

The system call clock_gettime() - clock and time functions indicate something like wait a little while and then try again.

To find out which file is causing the timeout, there should be symbolic link with the number 7, the integer representing the file in /proc/<PID>/fd/7

There is a socket as a symbolic link ont fd/4 -> socket:[6249981] (broken symbolic link). How can I continue debugging? @HBruijn — ibedelovski, Jul 11 '14 at 09:19
without a deeper understanding of the expected behavior (in this case: reading the PHP script) it would only be guess work. — HBruijn, Jul 11 '14 at 09:35
try 'lsof -p | grep 6249981'. You will probably find that it's a tcp connection or similar. — Robert Casey, Mar 23 '18 at 22:29

Describing `strace` command output

1 Answers1