Linux application/script debugging with ‘strace’

Every now and then, you'll encounter a problem with an application or a script that is not clear straight away. After the normal troubleshooting, it can be helpful to see the actual system calls that occur when that script executes. Using a tool like strace (manpage) can help you in identifying what is causing the system to slow down or misbehave.

In this blogpost I'll show you some examples where strace can be useful for you. Most of it will be with PHP code but they're easy enough anyone can understand them.

Installing strace

Strace isn't installed by default on most distributions. To install, do a simple yum install strace when on CentOS/Red Hat or apt-get install strace on Debian/Ubuntu systems.

Getting output from strace

You can use strace in two different ways. You can attach it to an already running process or you can use it to start a custom application or script and follow all system calls from the very beginning.

In short, here's how it goes. If you want to start your application and troubleshoot it from beginning to end, you do this:

~# strace -f $command
~# strace -f php -q somefile.php

Or you want to attach to a running process, use this:

~# strace -f -p $pid
~# strace -f -p 8151

The -f parameter tells strace to follow any children or processes that are spawned/forked from the application.

Standard usage of strace

By default, strace will show you -all- system calls that your application or script is performing. That can get pretty overwhelming, but it's a good place to start. Take for instance the following simple script called 'test1.php'.

<?php
   /* Simple buggy script */
   for ($i = 0; $i < 5; $i++)
      sleep(1);
?>

The command above will simply iterate over the loop and sleep (do absolutely nothing) for 1 second on each iteration. So, this would do nothing for exactly 5 seconds. Best script I've ever written! ;-)

If you were to strace the execution of the script, it would look like this.

~# strace php -q test1.php
execve("/usr/bin/php", ["php", "-q", "test1.php"], [/* 23 vars */]) = 0
brk(0)                                  = 0xa036000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
...
nanosleep({1, 0}, {1, 0})               = 0
...
nanosleep({1, 0}, {1, 0})               = 0
...
nanosleep({1, 0}, {1, 0})               = 0
...

At first, it's overwhelming. You don't need to understand every system call (sure, it helps, but the names of most functions explain the actions anyhow), but the execution can show you a few remarkable things straight away. When it's running, you'll see the application hang every second with the nanosleep({1, 0}, {1, 0}) = 0 message. The nanosleep() is the system call for the sleep() method in PHP. Without having seen the source code of the application, this tells you the application specifically requested to sleep() there and waited.

But since the output was a bit too much to work with, let's look at filtering it.

Write a Comment

Do you care about the markup if your comment? You can use the following HTML tags:

<code>command</code>: command highlighting
<pre>text</pre>: pre-formatted code, can be multi-line (black background, white letters)

example <pre> tag
<blockquote>text</blockquote> quoted text
quoted example


None of this is needed of course, it's all optional!

Comment

*