Troubleshooting is an important part of every DevOps engineer’s or SRE’s job.<\/p>\n
It could involve:<\/p>\n
- \n
- Database performance bottlenecks<\/li>\n
- Web server performance issues<\/li>\n
- Identifying slow requests<\/li>\n
- Excessive resource consumption<\/li>\n<\/ul>\n
and more\u2026<\/p>\n
The strace<\/strong> utility is useful for debugging various application issues by tracing system calls (syscalls).<\/p>\n
This blog is for educational purposes only.<\/strong> Do not use strace in production without understanding its effects on performance.<\/p><\/blockquote>\n
Scenario<\/h2>\n
Let\u2019s say the Nginx app wants to write a log entry<\/strong> to a file on the disk. Since Nginx cannot directly access hardware like disks, it must use syscalls to request kernel services.<\/p>\n
For example, Nginx might use the following syscalls:<\/p>\n
- \n
open()<\/code> \u2013 Opens log files once when Nginx starts – (not per write)<\/li>\nwrite()<\/code> \u2013 Writes the log entries to the file in buffered batches.<\/li>\nclose()<\/code> \u2013 Closes the file descriptors during log rotation\/shutdown<\/li>\n<\/ul>\nThat means Nginx is programmed to use syscalls whenever it needs to interact with the operating system for tasks like file operations, network handling, or process management.<\/p>\n
If you need to diagnose an issue related to an application’s performance, networking, or other system interactions, tracing syscalls can help you identify the problem.<\/p>\n
What is strace?<\/h2>\n
Strace is a linux command-line utility that intercepts and records all the system calls a program (eg: nginx) makes and any signals it receives.<\/p>\n
Lets look at a simple example.<\/p>\n
Lets look at a summary of system calls made when running the
ls<\/code> command.<\/p>\n![\"\"](\"https:\/\/storage.ghost.io\/c\/5f\/2f\/5f2f4d20-2abf-4534-8d40-7aa233aedd43\/content\/images\/2025\/03\/image-335.png\")
<\/figure>\nOverall, the command made 78 system calls with 7 errors total.<\/p>\n
Also, the execution time was extremely fast<\/strong> (all individual calls show 0.000000 seconds)<\/p>\n
Practical Debugging Example<\/h2>\n
To look at a practical debugging example using strace, I had to simulate a real-world scenario of a slow-responding page.<\/p>\n
To simulate this scenario, here\u2019s what I did:<\/p>\n
- \n
- Deployed Nginx with PHP-FPM.<\/li>\n
- Created a simple PHP page (
\/slow<\/code>) that responds only after 2 seconds. This is just to simulate a real-world scenario of a slow response page.<\/li>\n<\/ul>\nThe next step is to capture the syscalls made by Apache when accessing the
http:\/\/localhost\/slow<\/code> page.<\/p>\nTracing nginx syscalls<\/h3>\n
To trace the syscalls, we first need to get the Nginx worker process ID.<\/p>\n
ps aux | grep nginx<\/code><\/pre>\nNow, we need to attach strace to the process ID to trace system calls.<\/p>\n
Since we are investigating a slow-responding page, our focus should be on the syscalls involved in handling HTTP<\/strong> requests and responses.<\/p>\n
\n\ud83d\udca1<\/div>\nrecvfrom<\/strong><\/b> syscall receives data from a network socket (e.g., an HTTP request from a client).<\/div>\n<\/div>\nI am going to trace only the
recvfrom()<\/code> syscall using the following command. Here,13173<\/code> is the Nginx worker process ID.<\/p>\nsudo strace -e trace=recvfrom \\\n -p 13173 -f -T -tt -o strace.log<\/code><\/pre>\nNow that strace is tracing the calls, I generated 10 requests with 2 concurrent users to capture the logs in
strace.log<\/code> using apache benchmark utility.<\/p>\nab -n 10 -c 2 http:\/\/localhost\/slow<\/code><\/pre>\nNow that enough requests have been generated, the goal is to debug the slow response issue.<\/p>\n
If we check the
strace.log<\/code>, we will find complex log entries containingrecvfrom<\/code> syscalls, similar to the following.<\/p>\n![\"\"](\"https:\/\/media.beehiiv.com\/cdn-cgi\/image\/fit=scale-down,format=auto,onerror=redirect,quality=80\/uploads\/asset\/file\/172d6fb4-a720-413d-8278-adc47a711678\/image.png?t=1738319845\")
<\/figure>\nAnalysis of <\/strong>
recvfrom()<\/code> <\/strong>Log for Slow Requests<\/h2>\nLets look at the first two entries.<\/p>\n
13173 10:23:41.655745 recvfrom(5, \"GET \/slow HTTP\/1.0\\r\\nHost: localh\"..., 1024, 0, NULL, NULL) = 81 <0.000011>\n\n13173 10:23:41.656706 recvfrom(12, \"GET \/slow.php HTTP\/1.0\\r\\nHost: lo\"..., 1024, 0, NULL, NULL) = 104 <0.000005><\/code><\/pre>\nHere,<\/p>\n
- \n
- Client requests
\/slow<\/code>.<\/li>\n- Nginx forwards it to
\/slow.php<\/code> for processing.<\/li>\n- Time: 10:23:41.656706.<\/li>\n<\/ol>\n
The next log entry is the response from php.<\/p>\n
13173 10:23:43.659573 recvfrom(13, \"\\1\\6\\0\\1\\0,\\4\\0Content-type: text\/html;\"..., 4096, 0, NULL, NULL) = 72 <0.000041><\/code><\/pre>\nHere,<\/p>\n
- \n
- Response received from PHP after 2 seconds (10:23:43.659573).<\/li>\n
- Delay: 2.003 seconds.<\/strong><\/li>\n
- This suggests slow PHP execution (Which we simulated)<\/li>\n<\/ol>\n
Note:<\/strong> This is just an example of identifying slowness in an HTTP request. Depending on the issue, the relevant syscalls and the approach to analysis may vary.<\/p>\n
Strace & Performance<\/h2>\n
Strace is not advised to be used in production environments.<\/p>\n
One of the problems with strace is that it slows down applications significantly, especially in production.<\/p>\n
It uses
ptrace()<\/code>, which pauses the target process twice per system call (entry and exit). It could even lead to application crashes.<\/p>\nThis frequent pausing and context-switching adds high overhead to applications.<\/p>\n
- This suggests slow PHP execution (Which we simulated)<\/li>\n<\/ol>\n
- Nginx forwards it to
- Client requests
![\"\"](\"https:\/\/media.beehiiv.com\/cdn-cgi\/image\/fit=scale-down,format=auto,onerror=redirect,quality=80\/uploads\/asset\/file\/839842e0-fc34-4a4c-991d-c4dc0c12e3f6\/image.png?t=1738995410\")
<\/figure>\n