Files

200 lines
16 KiB
Plaintext
Raw Permalink Normal View History

Episode: 4572
Title: Uncommon Commands, Episode 3 - strace
Source: https://hub.hackerpublicradio.org/ccdn.php?filename=/eps/hpr4572/hpr4572.mp3
Transcribed: 2026-07-31 16:14:13 (official HPR transcript)
---
This is Hacker Public Radio Episode 4572, for 2026-02-10
Today's show is entitled, "Uncommon Commands, Episode 3 - strace"
The host is Deltaray and the duration is 00:17:01
The flag is Clean, and the license is CC-BY-SA
The summary is "An overview of how to run and read the output of the strace command."
Hello everybody and welcome to Hacker Public Radio. This is Delta Ray before I explain anything today
I want you to actually see something if you're at a Linux system right now or can be later
Try this simple command in the shell S trace space up time. That's S T R A C E space U P T I M E
So you run that and just run it once and let the output scroll by
If this is your first time seeing S trace the output probably looks a little like the matrix
You know the code that goes by on the screens there. It's a lot of text. There's some weird function names and numbers and hex codes everywhere
And if your first instinct is wow, I have no idea what I'm looking at
That's completely normal and probably what has put off most people from learning the command
But here's the important thing. You don't need to understand everything to start learning from it as
Uptime runs look near the bottom of the output
You'll likely see references to files like slash at C slash local time and slash proc slash up time
Those should already feel a little familiar slash out at C slash local time tells the program
What time zone the system is in and slash proc slash up time is where the kernel exposes how long the system has been running
So even though the output looks a bit overwhelming you can already see okay
This program is reading some files. I recognize now look for a line that includes something like right
W-R-I-T-E and then parentheses the number one comma and then the string that normally gets print out from the
Uptime command. This is probably it depends on you know how long your system has actually been up
But it might have like a
A laps time like hours min seconds followed by days maybe how many users are logged in and load average
But that right call is where uptime actually prints the text that you actually see on your screen when you run the uptime command
The one that's after the parentheses there is the file descriptor number for standard output
Standard output, you know, it means we're to print the output to the place the program will started from in this case the terminal window
So uptime isn't magically printing text it's explicitly
Asking the kernel please write these bytes to standard out and the kernel does exactly that
This is the key thing I want you to notice right away
S trace isn't magic it's simply showing you the conversation between a program in the operating system
files get opened data gets red text gets written
Once you see that the output starts to feel a little less intimidating and it's core
Estrace just shows system calls
System calls are how user space programs talk to the kernel
User space programs being the programs that you normally run when you run your system and the kernel being the back end brain for the operating system
That actually talks to the hardware
Anytime a program opens a file reads data writes output talks to the network creates a process
It has to ask the kernel to do that work because the kernel is what talks to the hardware
Estrace just lets you listen in
It's very similar to a program like TCP dump or wire shark if you've ever used that to listen to the network
Let me give you a real example of where estrace earned its keep early in my system administration career
I forced myself to get comfortable reading estrace output because I saw other system administrators using it
Not memorizing everything about it, but just learning how to recognize patterns some of the basic system calls and how the output for those system calls was presented
I used it occasionally for myself to find out why something was not working for me
But the real place where it's shined was later when I was working as a Linux system administrator at a mid-sized enterprise company
And we had this commercially developed application that just wouldn't work. It was failing and some weird way
We were trying to figure out where it was light writing files to the logs were vague the documentation wasn't great
And nothing obvious was jumping out, so we were just kind of guessing us to what it was doing
The other system administrators had theory they suspected the program was trying to read from or write to some directory
It didn't have access to
But that was about all it was a theory. We didn't have any way of proving it and the application certainly wasn't volunteering that information
This is where I suggested using estrace. I sat down sshed in to the system and ran estrace on the already running process
Just grabbing its PID its process ID and traced it live within seconds
There it was in black and white the program was trying to write a file to a specific directory and then read it back
And the directory had the wrong permissions on it
So there was no guess work, no assumptions. It just gave us evidence
What was funny was the reaction from the other system administrators the other admins were kind of stunned
They hadn't realized you could attach to a running process like that and just watch what it was doing at the system level
It was like I'd cast some magic spell or hack the system
This was one of those moments. I realized that I could create the CLI magic feed
But it wasn't magic. It was just asking the operating system. Hey, what is this program actually doing?
System calls or how operating systems work?
There is no deeper hidden layer show commands GUI applications
Demons containers everything eventually boils down to system calls like open read right
Stat fork exec fee. There's a whole bunch more out there and there's some newer ones that you might have
seen in the in the output of S trace
But I'm not going to get into all that essentially if you see something like open or open to or open add
It's still probably reading a file or opening a file
So once you internalize that S trace stops being scary and starts being more obvious
Now let's simplify things further try to running this command S trace space dash e space open at
So O P E N A T space
LS
So you basically running the LS command from S trace so that it all attached to the LS command right away
The dash e option tells S trace only show me file open relayed system calls
In other words the open at system call you have to be specific to whatever system call
You're trying to actually filter out this cuts down on the noise quite a bit as it's only gonna show you
The open add functions
So instead of thousands of lines of output you'll see a short list showing which files LS asks the kernel to open
You might see something like open at
AT
Fd CWD
O
Rd only oh
Directory equals three and you know a lot of that stuff. I mean, I you know, I can't really read it
But you can kind of get it's to it's talking about you know read only access maybe and and
A directory or something and CWD might mean current working directory
But that's not what really matters here the equals three at the end is probably the most important part
You don't need to understand everything here just a few pieces so open at is the system call the dot
That's in the middle of the system call is just the path that's being opened so the dot meaning the current
Directory that you're in and the equals three at the end is the file descriptor that's returned by the kernel
If you're not familiar with programming and file descriptors don't worry too much about that
It's basically just a way of referencing the file like the data that it's accessing
So in this case, it's assigning it to the number three
File descriptors are are just usually small integers
You'll see something like zero for standard input one for standard output and two for standard error
So when you see something like three four five those are additional files the program is opened
In this case three being the current directory that you're in
If the program that you're running happened to open up more files those numbers would increase more
But it's important to note that those numbers might need to be referenced later if you're looking at a more
Sophisticated S trace output of a of a bigger program
You might have to keep track of those numbers so that you can see where it actually reads from a file that opens and so on
So those numbers can help you figure those things out
Now let's try something that doesn't exist if you run S trace space dash e
Open at space LS and then it doesn't matter which put here maybe just put in slash does slash not slash exist
And you'll see something like open at followed by you know those those capital letter flags and then the path that you actually tried to
Open or list and you know does not exist and then the important part is at the end the negative one
ENO ENT that's incredibly useful. It's it's the kernel is telling you very plainly
I was asked to open a file and it does not exist so there's no guessing or mystery you can see right there
What the the output error code was from the kernel
If you later read uh if you later trace the read calls you'll see lines like read
Followed by parentheses and then you know the file handle number so maybe it's a three and then
Some extra arguments to that function
Followed by a number at the end. It's probably gonna be something like 4,096
It might be a different power of two but usually it's a power of two
Unless you're getting to the end of a file and then it might be whatever's left over
And so after that it's gonna say equals and then the last number is gonna be like 128 or
Something like that and that's how many bytes were actually read in
On that function call. So that's kind of useful. You can see how many actual bytes of data got read in
Not how many were requested but how many were returned
You don't need to master this right now. Just notice how explicit the kernel is being so that you can kind of get a sense of
Hey, this data is here. I can actually use this later and trying to diagnose a problem
There's another situation you're running into with strace. That's worth talking about
Sometimes you attach strace to a process and it just sits there. No scrolling no errors just one line
Maybe nothing at all and it usually means that it's waiting for something
So you might see something like read
Print the seeds three comma something and then 4,96 and then it's just sitting there and it doesn't return a prompt or anything
That means the program is waiting for input. So the program that it's stracing is waiting for some kind of data to come back
That could be data from a file from a
pipe from a socket from another process
It's not a crash. It's basically just blocking on IO
Waiting and you know at this point you might just yes say control c
But it could be that this will tell you you know that some things not what right with the program
Maybe something's not right with your file system or whatever
Most definitely if you try to hit control c here and it doesn't give you the prompt backed
And you can't cancel the strace process which I've run into before you probably do have some kind of problem with
Your storage device or something and the kernel isn't able to like give you back the data
The same idea applies to socket relayed calls if a process is just sitting in a network called
Offemines of swing for the remote service and a connection or data to arrive over the network
Again, it's not necessarily an error. It's just waiting
If you attach to if you attach strace and see no system calls happening that often means the program is busy doing work entirely in user space
Maybe calculations parsing compression, you know something like that until it needs to talk to the kernel again
There's nothing to show that distinction alone can save you a lot of time because you know, oh, it's actually doing something
Maybe it's stuck in infinite loop. It's it's hard to know but at least it gives you some kind of information
One thing that trips people up strace writes it's output to standard error
Not standard output. So you won't be able to do something like strace space LS pipe
Grap open. You're not going to actually be able to filter out those open requests that way
You can fix that by redirecting standard error to standard output
By using something like strace space LS space two greater than ampersand one which does the
Redirection and combining was standard output and then pipe that into Grap open
Or you can have strace right directly to a file which is what I usually do when I'm using strace and there's like a lot of output
So you use the dash oh option like this strace space dash oh space
The file that you want to log to so you might call like trace.log space LS or whatever command you want to run
So that dash oh option is very useful for when you're doing very large traces that you want to look at later
Maybe in using the less command or something like that
You can also attach strace to a running process. So for instance if you have like a demon or something like that
They want to monitor you can use the dash p option so it can be like strace space dash p space the process ID so make you know like one two three four five
And this lets you see what a program is doing right now as it's running when you're done you can press
Control c and it detaches strace in the process that you're you're monitoring keeps running in the background
Many programs also fork off in our words. They copy themselves and memory and make a new process
In the table and that can become confusing when you try to run strace again something because
The strace for the initial command will end and you won't actually
Continue tracing what you forked off and so in that case you need to use some options either dash f or dash f
In order to start following off the forked processes
So maybe you're running you know strace space dash f space my server or you know some some server
Command that you want to start
If you want to split the output in the separate files
So that you have an output file, but it creates a new file for every forked off process for instance like a web server
Does this kind of thing then you would use the dash f f option along with dash o and
You know the output file that you want and then it'll create a new file with the process ID and it's file name
For every forked off process so this way if you want to do something like monitor a web server
You can do that and you'll have a
Separate trace log for each of the requests that gets made. I've done this several times for for monitoring web servers
Astrace doesn't just help you debug it also changes your mental model instead of thinking this makes no sense
You start thinking what is a program asking the kernel to do?
You know behind each of those buttons in a gooey application and behind every one of those commands that you're
Running our system calls that are getting made to the kernel to do different things and that shift makes
Debugging comma more mechanical and much less emotional, you know, you're going to have a process to doing it
So if strace feels like black magic right now, that's normal
But it isn't magic it's literacy and
Once you have it you'll start seeing problems not as mysteries but as conversations between
Program and the kernel that you can finally listen to
Thanks for listening and as always welcome to hacker public radio
I hope that you take the time to actually record an episode in the future take care so long
You have been listening to Hacker Public Radio at Hacker Public Radio.org.
Today's show was contributed by a HPR listener like yourself.
If you ever thought of recording podcast, click on our upload link
to find out how easy it is.
Hosting for HPR has been kindly provided by an AnHonestHost.com, the Internet Archive,
rsync.net, and our mirror network.
Unless otherwise stated, today's show is released under a Creative Commons
Attribution-ShareAlike 4.0 International (CC BY-SA 4.0) license.