In my ongoing quest to understand more how GNU Linux works under the hood, I took upon myself a courageous assignment to figure out what a simple go program does from a kernel's point of view - which syscalls are called and what data is passed down there
Here is the program
So a simple hello world, which prints out the famous words and creates an empty file. To figure out which syscalls are triggered, I decided to use trace-cmd package. It is a frontend to ftrace which helps for example in filtering out the syscalls related to a single binary or a PID.
After some intense googling, watching a couple of youtube videos, and fiddling around, I ran this command.
sudo trace-cmd record -p function_graph --max-graph-depth 3 -e syscalls -g do_syscall_64 -F ./gohello
It records a list of kernel functions practically in the order they are called with max depth and some filtering. It shows only syscalls and not, for example, system interrupts that clutter the output and are not in this exercise's scope. I'll not go into too much detail since, frankly, I lack the competence to decipher what all the parameters mean.
The output looks like this
With this single program, there is a lot of output, thousands of lines even with the filtering. The example shows one interesting syscall, the SyS_write which is actually the call to write the "Hello world" plus timestamp to stdout.
We can actually take a closer look at the full stack of calls related to SyS_write
sudo trace-cmd record -p function_graph -g SyS_write -F ./gohello
I tried to look for clock_gettime or suchlike kernel calls to see which kernel function is used to get the current time but turns out, there are things called vDSO shared objects which map parts of the kernel memory to be directly accessible to usespace eliminating the need for a syscall. The go runtime reads the timestamp registry directly. Check the implementation here.
The file operation calls show in the above output. It all starts by reading the file path "./example.txt", opening files, creating file descriptors, piping data to it, and closing the file and fd. More on the functions can be found on their corresponding man pages.
- sys_readlinkat: https://man7.org/linux/man-pages/man2/readlinkat.2.html
- sys_fcntl: https://man7.org/linux/man-pages/man2/fcntl.2.html
- sys_openat: https://linux.die.net/man/2/openat
- sys_epoll_create1: https://man7.org/linux/man-pages/man2/epoll_create.2.html
- sys_pipe2: https://man7.org/linux/man-pages/man2/pipe.2.html
- sys_epoll_ctl: https://man7.org/linux/man-pages/man2/epoll_ctl.2.html
- sys_close: https://man7.org/linux/man-pages/man2/close.2.html
Ok, cool, we now know which are the most exciting syscalls. Obviously, there are more system calls, like a bunch of SyS_mmaps for mapping virtual memory pages, etc... but the next step is to take a look inside a selected few calls. For that, I use eBPF, or rather a frontend for it called bpftrace.
I have watched a number of presentations about the fascinating topic of eBPF and have played with bpftrace occasionally and I admit this is one of the main reasons of writing this post.
First up, lets see the file writing operations. We can take a look at the file open for example. Step one, find the tracepoint
sudo bpftrace -l "*openat"
Ok we have a tracepoint, next let's check which arguments we can trace
We can see the filename in the trace point arguments. The tracing call can be done with for example this one line bpf program
sudo bpftrace -e 'tracepoint:syscalls:sys_enter_openat { printf("%s %s\n", comm, str(args->filename)); }' -c ./gohello
In the output, you can see all the calls made to sys_openat during the program execution, and voila, there is example.txt
An interesting finding is that readlinkat is not related to the file path of example.txt but is a link to self.
We can also trace the sys_write calls, and whoo boy, are there plenty of those. We can attempt to filter those a bit with a PID constraint
sudo bpftrace -e 'tracepoint:syscalls:sys_enter_write /pid > 7000/ { printf("<%s>\n", str(args->buf, args->count)); }' -c ./gohello | less
And there you have it, a hello world amid all the mess!
Comments
Post a Comment