Tracing with strace

strace - a hands-on Linux lab on a real virtual machine.

The syscalls behind printf and fopen. Put strace on a working file reader and watch fopen become openat, the fgetc loop become one buffered read, and printf become write, all on file descriptors 0 through 3. Filter the trace with -e trace=, read the kernel answers line by line, and learn why read returning 0 means end of file. The window this lesson opens is the subject of the whole System Programming in C track.

In the File I/O lesson you built a program that opens a text file, counts its lines, and prints the total. It works. You wrote every line of it, so you know exactly what it does.

Or do you. Put a wiretap on that program, and the first thing it does is open a file you never asked for:

openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3

You never wrote openat. You never mentioned /etc/ld.so.cache. And this happens before your main function even starts running. Your program has been holding a conversation with the operating system this whole time, and you have only ever heard one side of it.

This lesson gives you the wiretap. It is called strace, and once you can read its output, no running program on a Linux box can keep secrets from you.

The black boxes below are a practice terminal: a safe sandbox that checks the one command each step teaches. Every output shown was captured from the real lab VM (Debian 12, gcc 12.2.0). The trace lines are real strace output, byte for byte.

Your program is not allowed to touch the hardware. It cannot read a disk, paint the screen, or open a network connection by itself. Only one program on the machine may do those things: the kernel, the core of the operating system that manages all hardware and all processes.

Think of the kernel as a bank vault with one teller window. Your program cannot walk into the vault. It walks up to the window, fills out a request slip, and hands it over. The kernel checks the slip, does the work inside the vault, and hands back a result.

Each request slip is a system call, or syscall for short. openat is a syscall that asks the kernel to open a file. read asks it to copy bytes out of an open file. write asks it to send bytes somewhere. close hands the file back.

Here is the part that surprises most people. The C functions you have been calling, printf, fopen, fgetc, are not syscalls. They are library functions: helper code that lives in the C library, called libc, which is loaded next to every C program. Library functions do the convenient paperwork inside your program, then file the real syscall for you. fopen fills out an openat slip. printf formats your text, then files a write slip.

strace is the wiretap on the teller window. It runs your program and prints every request slip the program hands to the kernel, with the kernel's answer next to it.

You will spend much of your career running programs you did not write and cannot read the source of. When one of them misbehaves, strace answers questions the program refuses to answer itself.

Which config file is it actually reading? strace shows the exact openat, full path included. Why does it say permission denied? strace shows which syscall failed, and with what error. Why is it frozen? strace shows the last request it made before it stopped answering.

You need no source code, no debugger, no recompile. If it runs, you can trace it. That is why strace is one of the first tools a Linux engineer reaches for on a sick system.

gdb, from the previous lesson, and strace answer different questions. gdb shows what your program is doing inside its own code. strace shows what your program is asking the kernel to do. Together they cover both sides of the window.

Here is the file reader. It is the same shape you built in the File I/O lesson: open the file named on the command line, count the newline characters, report the total. Read it top to bottom before you touch anything.

#include <stdio.h>

int main(int argc, char *argv[]) { if (argc != 2) { fprintf(stderr, "usage: %s <file>\n", argv[0]); return 1; }

FILE *f = fopen(argv[1], "r"); if (f == NULL) { perror(argv[1]); return 2; }

int lines = 0; int c; while ((c = fgetc(f)) != EOF) { if (c == '\n') { lines = lines + 1; } }

fclose(f); printf("%d lines\n", lines); return 0; }

[ ] a b c
[x] 3 lines
[ ] usage: ./fio <file>

>>> The loop never prints the characters it reads. It only counts newline characters, one per line, and printf reports the count once at the end: 3 lines. The usage message appears only when you forget the filename argument, because then argc is not 2.

First, build the test file. printf, which you know from Foundations, writes exactly the bytes you name, and \n is a line break. Three letters, three line breaks, six bytes total:

prompt: operator@camp:~$ answer: printf 'a\nb\nc\n' > three.txt|||printf "a\nb\nc\n" > three.txt output: hint: printf from Foundations, with \n for each line break: printf 'a\nb\nc\n' > three.txt

Now compile with warnings on and run it, the same rhythm as every lesson in this track:

prompt: operator@camp:~$ answer: gcc -Wall fio.c -o fio && ./fio three.txt output: 3 lines hint: Compile with warnings on, then run with the filename: gcc -Wall fio.c -o fio && ./fio three.txt

3 lines, as predicted. Nothing new yet, and that is the point: this program is small, boring, and fully understood. Now look again at the functions it calls. fopen, fgetc, fclose, printf. Every one of them is a libc library function. Not one of them is a syscall. So while this program ran just now, what did the kernel actually see? That is the question strace answers.

The basic form is strace ./program. That prints every syscall, and even our tiny reader makes dozens, most of them startup noise. So strace has a filter: -e trace= followed by the syscall names you care about, separated by commas, with no spaces.

We care about four: openat, read, write, close. The full command is:

strace -e trace=openat,read,write,close ./fio three.txt

One prediction before you run it.

[ ] fopen("three.txt", "r") = 3
[x] openat(AT_FDCWD, "three.txt", O_RDONLY) = 3
[ ] read(3, "a\nb\nc\n", 4096) = 6

>>> The kernel has never heard of fopen. That name exists only inside libc. At the teller window, the request slip is openat, so the trace shows the slip, not the function that filled it out. The read line comes later, when fgetc needs bytes.

prompt: operator@camp:~$ answer: strace -e trace=openat,read,write,close ./fio three.txt output: openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 close(3) = 0 openat(AT_FDCWD, "/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\0\20t\2\0\0\0\0\0"..., 832) = 832 close(3) = 0 openat(AT_FDCWD, "three.txt", O_RDONLY) = 3 read(3, "a\nb\nc\n", 4096) = 6 read(3, "", 4096) = 0 close(3) = 0 write(1, "3 lines\n", 83 lines ) = 8 +++ exited with 0 +++ hint: strace, the filter, then the program: strace -e trace=openat,read,write,close ./fio three.txt

Twelve lines, and only five of the syscalls come from code you wrote. Read the trace as a story in two acts.

Act one is the loader. Before main runs, a helper called the dynamic loader connects your program to libc. It looks up the address book at /etc/ld.so.cache, then opens libc itself at /lib/x86_64-linux-gnu/libc.so.6 and reads its first 832 bytes. Those bytes begin with \177ELF: the magic marker at the front of every Linux executable file. Every dynamically linked program on the machine performs this same ritual before its own code runs. That is the call you never made from the cold open, explained.

Act two is your code: an openat on three.txt that returns 3, two read calls, a close, and one strange looking write that seems to break in half. The very last line, +++ exited with 0 +++, is not a syscall at all. It is strace's sign-off, reporting that the program ended with exit code 0, the same number $? would show. The next step takes act two apart, line by line.

Here is your program again, with the four lines that turned into syscalls highlighted.

#include <stdio.h>

int main(int argc, char *argv[]) { if (argc != 2) { fprintf(stderr, "usage: %s <file>\n", argv[0]); return 1; }

FILE *f = fopen(argv[1], "r"); if (f == NULL) { perror(argv[1]); return 2; }

int lines = 0; int c; while ((c = fgetc(f)) != EOF) { if (c == '\n') { lines = lines + 1; } }

fclose(f); printf("%d lines\n", lines); return 0; }

Line 10, the fopen, became openat(AT_FDCWD, "three.txt", O_RDONLY) = 3. The = 3 after a syscall is the kernel's answer. For openat, the answer is a file descriptor: a small number the kernel hands you as a claim ticket for the open file. It works exactly like a coat check. You hand over a filename, you get ticket number 3, and from then on you refer to the file by its ticket.

Why 3? Because every program starts life with three tickets already taken. Descriptor 0 is standard input, 1 is standard output, 2 is standard error. You met these numbers in the redirection lessons of Foundations: when you typed 2> errors.txt, that 2 was this exact file descriptor. The first file you open yourself gets the next free number, 3.

Line 18, the fgetc loop, became read(3, "a\nb\nc\n", 4096) = 6. Read the slip left to right: from ticket 3, into a buffer, up to 4096 bytes at most. The answer = 6 means the kernel delivered 6 bytes, which is the entire file. Notice your loop called fgetc seven times, but the trace shows one read. libc fetched a big block in one trip to the window and served your fgetc calls from that buffer, one character at a time. Trips to the kernel are slow, so libc batches them. This is much of why library functions exist.

{ "kind": "memory", "cells": [ { "addr": "buf+0", "bytes": "61", "label": "a" }, { "addr": "buf+1", "bytes": "0a", "label": "newline" }, { "addr": "buf+2", "bytes": "62", "label": "b" }, { "addr": "buf+3", "bytes": "0a", "label": "newline" }, { "addr": "buf+4", "bytes": "63", "label": "c" }, { "addr": "buf+5", "bytes": "0a", "label": "newline" } ] }

The buffer's real address is different on every run, because the system randomizes memory layout (ASLR, as you saw in the pointers lesson). The offsets buf+0 through buf+5 stand in for whatever address your run uses. The byte values never change: 61 is the ASCII code for a, and 0a is the newline.

The second read, read(3, "", 4096) = 0, is what end of file looks like at the window. An answer of 0 bytes is not an error. It is the kernel saying the file has nothing left. libc turns that 0 into the EOF your loop tests for.

Then close(3) = 0: your fclose on line 24, returning the ticket. And finally, line 25:

write(1, "3 lines\n", 83 lines
)                = 8

That is printf. After formatting the %d into text, libc filed the slip write(1, "3 lines\n", 8): send 8 bytes to descriptor 1, standard output. The line looks chopped because two streams collided on your screen. strace prints its trace on standard error while your program speaks on standard output, and the terminal weaves the two together. Your program's real output, 3 lines, landed in the middle of strace's report of the very write that produced it. The rest of the slip arrives on the next line: the closing parenthesis and the kernel's answer, = 8, all 8 bytes delivered.

The splice point differs on every run, so your final line may look slightly different. To keep the streams apart, send the trace to a file with strace -o trace.txt ./fio three.txt, then read it with less.

Same binary, no recompile. Change one thing, the argument, and watch how far the ripple travels. Here is the error path from fio.c, a five-line fragment of the program you already compiled:

FILE *f = fopen(argv[1], "r"); if (f == NULL) { perror(argv[1]); return 2; }

[ ] Prints 0 lines and exits 0
[x] Prints missing.txt: No such file or directory and exits 2
[ ] Crashes with Segmentation fault

>>> Down at the window, openat comes back with an error instead of a ticket. libc sees that, makes fopen return NULL, and records the reason in a variable named errno. Your perror call turns that recorded reason into the human sentence after the colon, and return 2 sets the exit code. No crash, because the code checked for NULL instead of using it.

prompt: operator@camp:~$ answer: ./fio missing.txt; echo "exit: $?" output: missing.txt: No such file or directory exit: 2 hint: Run it, then read the exit code: ./fio missing.txt; echo "exit: $?"

One changed argument, and every layer reported it honestly. The kernel answered the openat with an error code named ENOENT, kernel shorthand for no such file or directory. libc translated that into fopen returning NULL and errno being set. Your code translated that into a perror message and exit code 2. The text after the colon is not something you wrote. It is the kernel's answer, carried up through every layer to your screen. From now on, when any Linux program tells you No such file or directory, you know which syscall said it first.

Three messages you will meet while tracing, what each means, and what to check first.

1. The file is not where you think it is

missing.txt: No such file or directory

This is errno ENOENT surfacing through perror: the openat syscall could not find the path. Check the filename spelling first, then check your current directory with pwd, because a relative path like three.txt is looked up from wherever you are standing.

2. gcc stops you before strace can start

Drop a semicolon while editing and the compile fails, so there is no binary to trace. Here is the literal shape of the message, captured from a small program named broken.c:

broken.c: In function 'main':
broken.c:5:13: error: expected ';' before '}' token
    5 |     return 7
      |             ^
      |             ;
    6 | }
      | ~

gcc names the file, the line, and the column, points a caret at where it gave up, and even prints the semicolon it believes is missing, right under the caret. The missing semicolon is almost always on the exact line gcc prints. Fix it and recompile. Nothing can be traced until the binary exists.

3. The trace line that looks broken

write(1, "3 lines\n", 83 lines
)                = 8

Not an error at all. This is the stdout and stderr weave from earlier in the lesson: strace reports on standard error, your program speaks on standard output, and the terminal interleaves them mid-line. The rest of strace's line lands below, with the = 8 answer. When it bothers you, strace -o trace.txt sends the trace to a file and leaves your program's output alone on the screen.

Scaffolding off. No command is shown in this step.

A teammate hands you the compiled fio binary and asks a simple question: what files does this thing touch when it runs on three.txt? You know the tool, and you know the four syscall names that tell the file story: openat, read, write, close. Trace exactly those four, nothing else, and read the answer off the screen.

prompt: operator@camp:~$ answer: strace -e trace=openat,read,write,close ./fio three.txt output: openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 close(3) = 0 openat(AT_FDCWD, "/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\0\20t\2\0\0\0\0\0"..., 832) = 832 close(3) = 0 openat(AT_FDCWD, "three.txt", O_RDONLY) = 3 read(3, "a\nb\nc\n", 4096) = 6 read(3, "", 4096) = 0 close(3) = 0 write(1, "3 lines\n", 83 lines ) = 8 +++ exited with 0 +++ hint: The filter flag is -e trace= with the four names separated by commas and no spaces, in front of ./fio three.txt

You just answered the question with evidence. It reads /etc/ld.so.cache and libc, because every dynamic program does, and the only file it opens by choice is three.txt. That is the whole strace skill in one motion: run the program under the wiretap, filter to the calls that matter, and read the kernel's side of the conversation.

You earned this table. Every row is something you ran or read in this lesson.

The mental model to keep: your C functions are clerks, not kings. fopen, fgetc, and printf do paperwork inside your process, and the kernel does the real work when they file an openat, read, or write. strace shows you the slips.

This window between your program and the kernel is a whole discipline. The System Programming in C track lives there: making syscalls directly, wiring processes together with pipes and sockets, and reading the kernel's own data structures. What you learned today is the front door to that track.

You can now see through a running program. strace puts the wiretap on, and -e trace= narrows it to the calls you care about. You can read the answers too: a descriptor ticket from openat, a byte count from read and write, a zero for end of file, and the three standing tickets 0, 1, and 2.

The module lab is Lab: CSV Parser. You will write a real program from scratch on a live VM: a parser that reads a CSV file into structs on the heap with malloc, prints what it parsed, and frees every byte. It is graded on outcome by check.sh, and it pulls together files, structs, and the heap from this whole module.

Take strace with you. When your parser opens its input file, you know the openat that really happens. When it reads, you know the buffered read underneath. And when something misbehaves, you now hold two wiretaps: gdb for inside the program, strace for the window to the

Practice Tracing with strace in a real Linux terminal at The Linux Camp. Progress is verified automatically as you type commands on the machine.