200 lines
16 KiB
Plaintext
200 lines
16 KiB
Plaintext
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.
|