Showing posts with label linux. Show all posts
Showing posts with label linux. Show all posts

December 23, 2021

Day 23 - What is eBPF?

By: Ania Kapuścińska (@lambdanis)
Edited by: Shaun Mouton (@sdmouton )

Like many engineers, for a long time I’ve thought of the Linux kernel as a black box. I've been using Linux daily for many years - but my usage was mostly limited to following the installation guide, interacting with the command line interface and writing bash scripts.

Some time ago I heard about eBPF (extended BPF). The first thing I heard was that it’s a programmable interface for the Linux kernel. Wait a second. Does that mean I can now inject my code into Linux without fully understanding all the internals and compiling the kernel? The answer turns out to be approximately yes!

An eBPF (or BPF - these acronyms are used practically interchangeably) program is written in a restricted version of C. Restricted, because a dedicated verifier checks that the program is safe to run in an BPF VM - it can’t crash, loop infinitely, or access arbitrary memory. If the program passes the check, it can be attached to some kind of event in the Linux kernel, and run every time this event happens.

A growing ecosystem makes it easier to create tools on top of BPF. One very popular framework is BCC (BPF Compiler Collection), containing a Python interface for writing BPF programs. Python is a very popular scripting language, for a good reason - simple syntax, dynamic typing and rich standard library make writing even complex scripts quick and fun. On top of that, bcc provides easy compilation, events attachment and output processing of BPF programs. That makes it the perfect tool to start experimenting with writing BPF code.

To run code examples from this article, you will need a Linux machine with a fairly recent kernel version (supporting eBPF). If you don’t have a Linux machine available, you can experiment in a Vagrant box. You will also need to install Python bcc package.

Very complicated hello

Let’s start in a very unoriginal way - with a “hello world” program. As I mentioned before, BPF programs are written in (restricted) C. A BPF program printing “Hello World!” can look like that:

hello.c

#define HELLO_LENGTH 13

BPF_PERF_OUTPUT(output);

struct message_t {
   char hello[HELLO_LENGTH];
};

static int strcp(char *src, char *dest) {
   for (int i = 0; src[i] != '\0'; i++) {
       dest[i] = src[i];
   }
   return 0;
};

int hello_world(struct pt_regs *ctx) {
   struct message_t message = {};
   strcp("Hello World!", message.hello);
   output.perf_submit(ctx, &message, sizeof(message));
   return 0;
}

The main piece here is the hello_world function - later we will attach it to a kernel event. We don’t have access to many common libraries, so we are implementing strcp (string copy) functionality ourselves. Extra functions are allowed in BPF code, but have to be defined as static. Loops are also allowed, but the verifier will check that they are guaranteed to complete.

The way we output data might look unusual. First, we define a perf ring buffer called “output” using the BPF_PERF_OUTPUT macro. Then we define a data structure that we will put in this buffer - message_t. Finally, we write to the “output” buffer using perf_submit function.

Now it’s time to write some Python:

hello.py

from bcc import BPF

b = BPF(src_file="hello.c")
b.attach_kprobe(
   event=b.get_syscall_fnname("clone"),
   fn_name="hello_world"
)

def print_message(_cpu, data, _size):
   message = b["output"].event(data)
   print(message.hello)

b["output"].open_perf_buffer(print_message)
while True:
   try:
       b.perf_buffer_poll()
   except KeyboardInterrupt:
       exit()

We import BPF from bcc as BPF is the core of the Python interface with eBPF in the bcc package. It loads our C program, compiles it, and gives us a Python object to operate on. The program has to be attached to a Linux kernel event - in this case it will be the clone system call, used to create a new process. The attach_kprobe method hooks the hello_world C function to the start of a clone system call.

The rest of Python code is reading and printing output. A great functionality provided by bcc is automatic translation of C structures (in this case “output” perf ring buffer) into Python objects. We access the buffer with a simple b[“output”], and use open_perf_buffer method to associate it with the print_message function. In this function we read incoming messages with the event method. The C structure we used to send them gets automatically converted into a Python object, so we can read “Hello World!” by accessing the hello attribute.

To see it in action, run the script with root privileges:


> sudo python hello.py

In a different terminal window run any commands, e.g. ls. “Hello World!” messages will start popping up.

Does it look awfully complicated for a “hello world” example? Yes, it does :) But it covers a lot, and most of the complexity comes from the fact that we are sending data to user space via a perf ring buffer.

In fact, similar functionality can be achieved with much simpler code. We can get rid of the complex printing logic by using the bpf_trace_printk function to write a message to the shared trace_pipe. Then, in Python script we can read from this pipe using trace_print method. It’s not recommended for real world tools, as trace_pipe is global and the output format is limited - but for experiments or debugging it’s perfectly fine.

Additionally, bcc allows us to write C code inline in the Python script. We can also use a shortcut for attaching C functions to kernel events - if we name the C function kprobe__<kernel function name>, it will get hooked to the desired kernel function automatically. In this case we want to hook into the sys_clone function.

So, hello world, the simplest version, can look like this:

from bcc import BPF

BPF(text='int kprobe__sys_clone(void *ctx) { bpf_trace_printk("Hello World!\\n"); return 0; }').trace_print()

The output will be different, but what doesn’t change is that while the script is running, custom code will run whenever a clone system call is starting.

What even is an event?

Code compilation and attaching functions to events are greatly simplified by the bcc interface. But a lot of its power lies in the fact that we can glue many BPF programs together with Python. Nothing prevents us from defining multiple C functions in one Python script and attaching them to multiple different hook points.

Let’s talk about these “hook points”. What we used in the “hello world” example is a kprobe (kernel probe). It’s a way to dynamically run code at the beginning of Linux kernel functions. We can also define a kretprobe to run code when a kernel function returns. Similarly, for programs running in user space, there are uprobes and uretprobes.

Probes are extremely useful for dynamic tracing use cases. They can be attached almost anywhere, but that can cause stability problems - a function rename could break our program. Better stability can be achieved by using predefined static tracepoints wherever possible. Linux kernel provides many of those, and for user space tracing you can define them too (user statically defined tracepoints - USDTs).

Network events are very interesting hook points. BPF can be used to inspect, filter and route packets, opening a whole sea of possibilities for very performant networking and security tools. In this category, XDP (eXpress Data Path) is a BPF framework that allows running BPF programs not only in Linux kernel, but also on supported network devices.

We need to store data

So far I’ve mentioned functions attached to other functions many times. But interesting computer programs generally have something more than functions - a state that can be shared between function calls. That can be a database or a filesystem, and in the BPF world that’s BPF maps.

BPF maps are key/value pairs stored in Linux kernel. They can be accessed by both kernel and user space programs, allowing communication between them. Usually BPF maps are defined with C macros, and read or modified with BPF helpers. There are several different types of BPF maps, e.g.: hash tables, histograms, arrays, queues and stacks. In newer kernel versions, some types of maps let you protect concurrent access with spin locks.

In fact, we’ve seen a BPF map in action already. The perf ring buffer we’ve created with BPF_PERF_OUTPUT macro is nothing more than a BPF map of type BPF_MAP_TYPE_PERF_EVENT_ARRAY. We also saw that it can be accessed from Python bcc script, including automatic translation of items structure into Python objects.

A good, but still simple example of using a hash table BPF map for communication between different BPF programs can be found in “Linux Observability with BPF” book (or in the accompanying repo). It’s a script using uprobe and uretprobe to measure duration of a Go binary execution:

from bcc import BPF

bpf_source = """
BPF_HASH(cache, u64, u64);
int trace_start_time(struct pt_regs *ctx) {
 u64 pid = bpf_get_current_pid_tgid();
 u64 start_time_ns = bpf_ktime_get_ns();
 cache.update(&pid, &start_time_ns);
 return 0;
}
"""

bpf_source += """
int print_duration(struct pt_regs *ctx) {
 u64 pid = bpf_get_current_pid_tgid();
 u64 *start_time_ns = cache.lookup(&pid);
 if (start_time_ns == 0) {
   return 0;
 }
 u64 duration_ns = bpf_ktime_get_ns() - *start_time_ns;
 bpf_trace_printk("Function call duration: %d\\n", duration_ns);
 return 0;
}
"""

bpf = BPF(text = bpf_source)
bpf.attach_uprobe(name = "./hello-bpf", sym = "main.main", fn_name = "trace_start_time")
bpf.attach_uretprobe(name = "./hello-bpf", sym = "main.main", fn_name = "print_duration")
bpf.trace_print()

First, a hash table called “cache” is defined with the BPF_HASH macro. Then we have two C functions: trace_start_time writing the process start time to the map using cache.update(), and print_duration reading this value using cache.lookup(). The former is attached to a uprobe, and the latter to uretprobe for the same function - main.main in hello-bpf binary. That allows print_duration to, well, print duration of the Go program execution.

Sounds great! Now what?

To start using the bcc framework, visit its Github repo. There is a developer tutorial and a reference guide. Many tools have been built on the bcc framework - you can learn them from a tutorial or check their code. It’s a great inspiration and a great way to learn - code of a single tool is usually not extremely complicated.

Two goldmines of eBPF resources are ebpf.io and eBPF awesome list. Start browsing any of those, and you have all your winter evenings sorted :)

Have fun!

December 19, 2010

Day 19 - Upstart

This article was written by Jordan Sissel (@jordansissel)

In past sysadvents, I've talked about babysitting services and showed how to use supervisord to achieve it. This year, Ubuntu started shipping its release with a new init system called Upstart that has babysitting built in, so let's talk about that. I'll be doing all of these examples on Ubuntu 10.04, but any upstart-using system should work.

For me, the most important two features of Upstart are babysitting and events. Upstart supports the simple runner scripts that daemontools, supervisord, and other similar-class tools support. It also lets you configure jobs to respond to arbitrary events.

Diving in, let's take a look the ssh server configuration Ubuntu ships for Upstart (I edited for clarity). This file lives as /etc/init/ssh.conf:

description     "OpenSSH server"

# Start when we get the 'filesystem' event, presumably once the file
# systems are mounted. Stop when shutting down.
start on filesystem
stop on runlevel S

expect fork
respawn
respawn limit 10 5
umask 022
oom never

exec /usr/sbin/sshd

Some points:

  • respawn - tells Upstart to restart it if sshd ever stops abnormally (which means every exit except for those caused by you telling it to stop).
  • oom never - Gives hints to the Out-Of-Memory killer. In this case, we say never kill this process. This is super useful as a built-in feature.
  • exec /usr/bin/sshd - no massive SysV init script, just one line saying what binary to run. Awesome!

Notice:

  • No poorly-written 'status' commands.
  • No poorly-written /bin/sh scripts
  • No confusing/misunderstood restart vs reload vs stop/start semantics.

The initctl(8) command is the main interface to upstart, but there are shorthand commands status, stop, start, and restart. Let's query status:

% sudo initctl status ssh
ssh start/running, process 1141

# Or this works, too (/sbin/status is a symlink to /sbin/initctl):
% sudo status ssh 
ssh start/running, process 1141

# Stop the ssh server
% sudo initctl stop ssh
ssh stop/waiting

# And start it again
% sudo initctl start ssh 
ssh start/running, process 28919

Honestly, I'm less interested in how to be a user of upstart and more interested in running processes in upstart.

How about running nagios with upstart? Make /etc/init/nagios.conf:

description "Nagios"
start on filesystem
stop on runlevel S
respawn

# Run nagios
exec /usr/bin/nagios3 /etc/nagios3/nagios.cfg

Let's start it:

% sudo initctl start nagios
nagios start/running, process 1207
% sudo initctl start nagios
initctl: Job is already running: nagios

Most importantly, if something goes wrong and nagios crashes or otherwise dies, it should restart, right? Let's see:

% sudo initctl status nagios
nagios start/running, process 4825
% sudo kill 4825            
% sudo initctl status nagios
nagios start/running, process 4904

Excellent.

Events

Upstart supports simple messages. That is, you can create messages with 'initctl emit [KEY=VALUE] ...' You can subscribe to an event in your config by specifying 'start on ...' and same for 'stop.' A very simple example:

# /etc/init/helloworld.conf
start on helloworld
exec env | logger -t helloworld

Now send the 'helloworld' message, but also set some parameters in that message.

% sudo initctl emit helloworld foo=bar baz=fizz

And look at the logger results (writes to syslog)

2010-12-19T11:03:29.000+00:00 ops helloworld: UPSTART_INSTANCE=
2010-12-19T11:03:29.000+00:00 ops helloworld: foo=bar
2010-12-19T11:03:29.000+00:00 ops helloworld: baz=fizz
2010-12-19T11:03:29.000+00:00 ops helloworld: UPSTART_JOB=helloworld
2010-12-19T11:03:29.000+00:00 ops helloworld: TERM=linux
2010-12-19T11:03:29.000+00:00 ops helloworld: PATH=/usr/local/sbin:/usr/local/bin:/usr/bin:/usr/sbin:/sbin:/bin
2010-12-19T11:03:29.000+00:00 ops helloworld: UPSTART_EVENTS=helloworld
2010-12-19T11:03:29.000+00:00 ops helloworld: PWD=/

You can also conditionally accept events with key/value settings, too. See the init(5) manpage for more details.

Additionally, you can start jobs and pass parameters to the job with start helloworld key1=value1 ...

Problems

Upstart has issues.

First: Debugging it sucks. Why is your pre-start script failing? There's no built-in way to capture the output and log it. You're best doing 'exec 2> /var/log/upstart.${UPSTART_JOB}.log' or something similar. Your only option for capturing output otherwise is the 'console' setting which lets you send output to /dev/console, but that's not useful.

Second: The common 'graceful restart' idiom (test then restart) is hard to implement directly in Upstart. I tried one way, which is to in the 'pre-start' perform a config test, and on success, copy the file to a 'good' file and running on that, but that doesn't work well for things like Nagios that can have many config files:

# Set two variables for easier maintainability:
env CONFIG_FILE=/etc/nagios3/nagios.cfg
env NAGIOS=/usr/sbin/nagios3

pre-start script
  if $NAGIOS -v $CONFIG_FILE ; then
    # Copy to '<config file>.test_ok'
    cp $CONFIG_FILE ${CONFIG_FILE}.test_ok
  else
    echo "Config check failed, using old config."
  fi
end script

# Use the verified 'test_ok' config
exec $NAGIOS $CONFIG_FILE.test_ok

The above solution kind of sucks. The right way to implement graceful restart , with upstart, is to implement the 'test' yourself and only call initctl restart nagios on success - that is, keep it external to upstart.

Third: D-Bus (the message backend for Upstart) has very bad user documentation. The system seems to support access control, but I couldn't find any docs on the subject. Upstart doesn't seem to mention how, but you can see access control in action when you try to 'start' ssh as non-root:

initctl: Rejected send message, 1 matched rules; type="method_call",
sender=":1.328" (uid=1000 pid=29686 comm="initctl)
interface="com.ubuntu.Upstart0_6.Job" member="Start" error name="(unset)"
requested_reply=0 destination="com.ubuntu.Upstart" (uid=0 pid=1 comm="/sbin/init"))

So, there's access control, but I'm not sure anyone knows how to use it.

Fourth: There's no "died" or "exited" event to otherwise indicate that a process has exited unexpectedly, so you can't have event-driven tasks that alert you if a process is flapping or to notify you otherwise that it died.

Fifth: Again on the debugging problem, there's no way to watch events passing along to upstart. strace doesn't help very much:

% sudo strace -s1500 -p 1 |& grep com.ubuntu.Upstart
# output edited for sanity, I ran 'sudo initctl start ssh'
read(10, "BEGIN ... binary mess ... /com/ubuntu/Upstart ... GetJobByName ...ssh\0", 2048) = 127
...

Lastly, the system feels like it was built for desktops: lack of 'exited' event, confusing or missing access control, stopped state likely being lost across reboots, no slow-starts or backoff, little/no output on failures, etc.

Conclusion

Anyway, despite some problems, Upstart seems like a promising solution to the problem of babysitting your daemons. If it has no other benefit, the best benefit is that it comes with Ubuntu 10.04 and beyond, by default, so if you're an Ubuntu infrastructure, it's worth learning.

Further reading:

December 16, 2010

Day 16 - Introduction to LVM

This was written by Ben Cotton (@funnelfiasco)

Logical volume management (LVM) is not a new concept -- it first appeared in Linux in 1998 and had existed in HP-UX before then. Still, some sysadmins, new and old, aren't familiar with it. LVM is a form of storage virtualization that allows for more configuration flexibility than the traditional on-disk partitions. In fact, LVM is a kind of anti-partitioning, where multiple devices can be grouped together. In this article, we'll assume you've got a spare machine or VM to follow along on. If not, you can use losetup to create file-based "disks" (see the man page for instructions).

LVM setup starts with physical volumes. You mark disk devices (drives or partitions) as physical volumes with the pvcreate command. Physical volumes are then grouped together into one or more volume groups with vgcreate. It's most common to create a single volume group, but there are cases when multiple volume groups might be desirable. For example, one vg may be created on a solid-state drive to use for read-mostly data, with spinning disk(s) in a separate vg for more volatile data.

# Initialize two drives for use in LVM
pvcreate /dev/sda1 /dev/sdb1
# Create a single volume group called "myvg"
vgcreate myvg /dev/sda1 /dev/sdb1

Once the vg is created, you can generally think of it as a single disk. Instead of partitioning it as you would with a traditional flat disk, space is carved up by creating logical volumes with lvcreate. After a lv is created, any OS-supported file system can be made on it. (Note: it's important to consider your use case when selecting the file system to put on an lv. Not only do file systems have different performance characteristics, but if you want to grow or shrink the file system later, you'll have to use a file system that supports such operations. XFS and JFS in particular do not support shrinking.)

# Create a 10 GB logical volume for MySQL in myvg
lvcreate -L 10G -n mysql myvg
# Create a 1 TB logical volume for MythTV in myvg
lvcreate -L  1T -n mythtv myvg
# file system creation omitted

Instead of the traditional /dev/sdxn nomenclature, the logical volumes are available as /dev/mapper/$vgname-$lvname or /dev/$vgname/$lvname (e.g. /dev/mapper/vg00-usr or /dev/vg00/usr). This lack of numbering hints at the most beneficial feature of LVM -- the ability to flexibly re-allocate disk space. In traditional partitions, you generally create the partition layout you think you need and then hope your needs don't change. Although it's possible to re-configure a disk after it's been used, it can get messy, and is generally very difficult to do on a live system. With LVM, you can start out by provisioning a small amount of disk space and then growing the file systems as needed.

One real-life example is the case of a file server. In a previous job, we had a many-TB file server which groups in the department purchased space on. Five slices were available on each drive (actually a LUN from a SAN), and if a group outgrew the LUN it was on, we had to split their data across two LUNs. Additionally, if two groups were on the same LUN, we'd have to shift data around as they competed for space (which happened a lot). Had we used LVM instead, each group could have an LV in the correct size and they'd only compete with themselves.

In my current job, we leave most of the disk space on infrastructure servers unallocated. As the need for a particular file system grows, we grow that file system. Does the new temperature monitoring system blow up the /var file system? Grow it. Need to add more applications to /opt? Grow it. The flexibility LVM provides allows us to quickly adapt to the needs of the research we support.

For file systems that support online resizing, growing an lv is a simple process. The first step is to check to see if you've got enough disk space available by looking at the "Free PE / Size" line of the output from vgdisplay. The lv is resized with the lvresize command. Absolute and relative sizes can be used, and unit abbreviations like G and T are supported. After the lv has been resized, the file system still needs to be grown the appropriate tools (e.g. resize2fs).

# All your data[base] are belong to us. Need more space for MySQL
lvresize -L +5G /dev/myvg/mysql

Once the volume group is completely allocated, lvresize can be used to shrink an overgrown lv after the file system has been shrunk. Additional disks or partitions can be added to the volume group as well. After pvcreate has been run as above, the vgextend command can be used to add the physical volume to the volume group. This makes LVM somewhat similar to JBOD in that it can take disks of various sizes and combine them into a single usable unit.

# There's nothing good on TV. Shrink the MythTV lv
lvresize -L -10 /dev/myvg/mythtv
# We added another disk, put it in myvg
pvcreate /dev/sdc1
vgextend myvg /dev/sdc1

Flexibility isn't the only advantage that LVM provides sysadmins. LVM also has optional snapshots. If there's a volatile file system that doesn't lend itself to live backups (e.g. our database), an LVM snapshot volume can be used to allow the backup to run. Snapshot volumes generally only need to be a small fraction of the original lv (10-15% is a number I've seen frequently), but the key point is that the snapshot lv size must be large enough to hold the changes that happen to the original snapshot. Thus it is better to overestimate the size of the snapshot volume.

# Create a snapshot volume for our MySQL file system
lvcreate -L 2G -s -n dbbackup /dev/myvg/mysql
# Mount the snapshot for the backup program (tar? rsync?)
mount /dev/myvg/mysql /mnt

Although LVM can be set up on software RAID (md) devices, it also has some built-in RAID-like features. If the volume group has at least three devices, mirroring can be used for logical volumes (the third device is a log, with a live copy on one device and a mirrored copy on the second device). To use mirroring, the logical volume needs to be created with the -m or --mirrors option, which take the argument n-1 for n copies.

# Create an important data volume with two copies
lvcreate -L 50G -m 1 -n important myvg

LVM also has a striping feature which allows the logical volume to be striped across two or more devices. Unlike the striping in RAID 5/6, LVM striping has no checksum and therefore provides no data protection. However, because I/O operations are spread across multiple devices, performance is improved. The number of stripes can vary between 2 and the number of devices and is specified by -i or --stripes. The size of the stripe (in KB) is specified with -I or --stripesize and must be a power of 2.

# Create a 100GB 3-striped lv
lvcreate -L 100G -i 3 -I 4 -n fastlv myvg

LVM isn't all sunshine and rainbows, though. In the past, LVM support was not baked in to initrd files and so it had to be manually included after a kernel update. That's not as much of a concern anymore as most distributions include LVM support, but users of custom kernels should make sure the initrd contains LVM support if the root partition is on a logical volume. Because of this historical issue, many admins still opt for paranoia and put / (or at least /boot) on a traditional partition. Additionally, LVM presents an additional level of abstraction that can make recovery via Knoppix or a similar method more difficult. Still, LVM offers a great deal of flexibility that makes it indispensable to the system administrator.

Further reading:

December 15, 2010

Day 15 - Down the 'ls' Rabbit Hole

By: Adam Fletcher (@adamfblahblah)

From ls(1) to the kernel and back again.

Too often sysadmins are afraid to dive into the source code of our core utilities to see how they really work. We're happy to edit our scripts but we don't do the same with our command line utilities, libraries, and kernel. Today we're going to do some source diving in those core components. We'll answer the age-old interview question, "What happens when you type ls at the command line and press enter?" The answer to this question has infinite depth, so I'll leave out some detail, but I'll capture the essence of what is going, and I'll show the source in each component as we go. The pedants in the crowd may find much to gripe about but hopefully they'll do so by posting further detail in the comments.

Requirements

It'll be helpful if you install the source on your machine for the software we'll be looking at. Below are the commands I used to get the source for the needed packages on Ubuntu 9.10, and similar packages are available for your Linux distribution.


apt-get install linux-source 
apt-get source coreutils 
apt-get source bash
apt-get source libc6
apt-get install manpages-dev

I'm using linux-source version 2.6.31.22.35, coreutils (for the code to ls) version 7.4-2ubuntu1, bash version 3.5.21, and libc6 version 2.10.1-0ubuntu18, and finally manpages-dev to get the programmer's man pages.

Starting Out - strace & bash

One of the most useful tools in the sysadmin's arsenal is strace, a command that will show you most of the standard library and system calls a program makes while it executes. We'll use this tool extensively to figure out what code we are looking for in each component.

Let's start by strace'ing bash when it runs ls. To do so, we'll start a new instance of bash under strace. Note that I'll be cutting the output of strace down a lot in the post for readability.

adamf@kid-charlemagne:~/foo$ strace bash
execve("/bin/bash", ["bash"], [/* 30 vars */]) = 0

[... wow that's a lot of output ...]


write(2, "adamf@kid-charlemagne:~/foo$ ", 29adamf@kid-charlemagne:~/foo$ ) = 29
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
read(0,

... and that's where the output stops. If you're new to strace the key to reading it is to make liberal use of man pages to figure out what each library call does. Be aware that the relevant pages you want are in section 2 of the man pages, so you'll need to do man 2 read to find the page on read; this is because many of the system functions have the same name as regular commands that are found in chapter 1 of the man pages.

The read call is waiting for input on file descriptor 0, which is standard input. So we type ls and hit enter (you'll see more read & write calls as you type).

There's a lot of output, but we know we want to see ls related output, so let's do the simple thing and look at the lines that have ls in them:

stat("/usr/local/sbin/ls", 0x7fff03f1fd60) = -1 ENOENT (No such file or directory)
stat("/usr/local/bin/ls", 0x7fff03f1fd60) = -1 ENOENT (No such file or directory)
stat("/usr/sbin/ls", 0x7fff03f1fd60)    = -1 ENOENT (No such file or directory)
stat("/usr/bin/ls", 0x7fff03f1fd60)     = -1 ENOENT (No such file or directory)
stat("/sbin/ls", 0x7fff03f1fd60)        = -1 ENOENT (No such file or directory)
stat("/bin/ls", {st_mode=S_IFREG|0755, st_size=114032, ...}) = 0
stat("/bin/ls", {st_mode=S_IFREG|0755, st_size=114032, ...}) = 0

If we man 2 stat we see that stat returns information about a file if it can find it, and an error if it can't (much more on stat later). In this case what bash is doing is searching my $PATH environment variable in hopes of finding an executable file with the name ls. Bash will stat every directory in my $PATH, and if it can't find the file it returns command not found. In this case, Bash found ls in /bin, and then that's the last we see of the string ls in our output.

We don't see ls in our output anymore because once Bash knows it can execute the program it spawns a child process to execute that program, and we haven't told strace to follow children of the command it is tracing. It's the next few lines of strace that give this spawning away:

pipe([3, 4])                            = 0
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f2c853217c0) = 30125

If we man 2 pipe and man 2 clone we see that bash is creating a pipe (two file descriptors that can be read and written to; this way a shell can link commands input and output together when you give the shell a | character) and clone'ing itself so that there are two copies of bash running. Remember, every UNIX process is a child of another process, and a brand new process starts out as a copy of its parent. So when does ls actually happen? Let's strace ls and find out!

adamf@kid-charlemagne:~/foo$ strace ls
execve("/bin/ls", ["ls"], [/* 30 vars */]) = 0

That first line is the key. execve is the library call to load and run a new executable. Once execve runs we're actually ls (well, the loader runs first, but that's another article). Interestingly, the call to execve is in the bash source code, not the ls source code. Let's find it in the bash code:

adamf@kid-charlemagne:/usr/src/bash-4.0/bash-4.0$ find . | xargs grep -n "execve ("
./builtins/exec.def:201:  shell_execve (command, args, env);
./execute_cmd.c:4323:   5) execve ()
./execute_cmd.c:4466:      exit (shell_execve (command, args, export_env));
./execute_cmd.c:4577:  return (shell_execve (execname, args, env));
./execute_cmd.c:4653:/* Call execve (), handling interpreting shell scripts, and handling
./execute_cmd.c:4656:shell_execve (command, args, env)
./execute_cmd.c:4665:  execve (command, args, env);

If we look at line 4323 in execute_cmd.c we see this helpful comment:

/* Execute a simple command that is hopefully defined in a disk file
somewhere.

1) fork ()
2) connect pipes
3) look up the command
4) do redirections
5) execve ()
6) If the execve failed, see if the file has executable mode set.
If so, and it isn't a directory, then execute its contents as
a shell script.
[...]
*/

And looking at line 4665 we do see the call to execve. Take a look at the code around execve - it's a bunch of error handling but nothing too hard to understand. What's interesting is what is not there; the code exists only to handle errors and nothing to handle success. That is because execve will only return if there's a failure, which makes sense - a successful call to execve means we're running something completely different!

Look around execute_cmd.c at the code around calls to shell_execve and you'll see that that code is fairly straightforward.

Inside ls(1)

Let's look at what ls is doing by creating a single file in our directory and ls'ing that file under strace.

adamf@kid-charlemagne:~/foo$ touch bar
adamf@kid-charlemagne:~/foo$ strace ls bar
execve("/bin/ls", ["ls", "bar"], [/* 30 vars */]) = 0

Interesting! We can see that bar is now being passed to our execve call. Let's keep looking at the strace output to find bar:

stat("bar", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
lstat("bar", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f467abbe000
write(1, "bar\n", 4bar
)                    = 4

Right at the end of the strace output we see bar a few times. It looks like bar gets passed to stat, lstat, and write. Working backwards, we can man 2 write to figure out that write sends data to a file descriptor, in this case standard out, which is our screen. So the call to write is just ls printing out bar. The next two library calls, stat and lstat, share a man page, with the difference between the commands being that lstat will get information on a symbolic link while stat will only get information on a file. Let's look in in the ls source code for these calls to see why ls does both lstat and stat:

adamf@kid-charlemagne:/usr/src/coreutils-7.4/src$ grep -n "stat (" ls.c
967:      assert (0 <= stat (Name, &sb));       \ 
2437:      ? fstat (fd, &dir_stat)
2438:      : stat (name, &dir_stat)) < 0)
2721:     err = stat (absolute_name, &f->stat);
2730:         err = stat (absolute_name, &f->stat);
2749:     err = lstat (absolute_name, &f->stat);
2837:         && stat (linkname, &linkstats) == 0)

That call to lstat stands out amongst the other calls, and so it is a pretty good guess that lstat happens for some exceptional reason that programmer would notate with a comment. Looking at line 2749 in ls.c we see an interesting comment a few lines above:

         /* stat failed because of ENOENT, maybe indicating a dangling
             symlink.  Or stat succeeded, ABSOLUTE_NAME does not refer to a
             directory, and --dereference-command-line-symlink-to-dir is
             in effect.  Fall through so that we call lstat instead.  */
        }

    default: /* DEREF_NEVER */
      err = lstat (absolute_name, &f->stat);
      do_deref = false;
      break;
    }

That comment means that if we're not talking about a directory and stat has already succeeded, we need to see if we are looking at a symlink. We can see that this is true by ls'ing a directory under strace:

adamf@kid-charlemagne:~/foo$ strace ls /home/adamf/foo/
[...]
stat("/home/adamf/foo/", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
open("/home/adamf/foo/", O_RDONLY|O_NONBLOCK|O_DIRECTORY|O_CLOEXEC) = 3
fcntl(3, F_GETFD)                       = 0x1 (flags FD_CLOEXEC)
getdents(3, /* 3 entries */, 32768)     = 72
getdents(3, /* 0 entries */, 32768)     = 0
close(3)                                = 0
fstat(1, {st_mode=S_IFCHR|0620, st_rdev=makedev(136, 0), ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f873dda4000
write(1, "bar\n", 4bar

Note that there was no call to lstat this time.

Where We Are Going There Is No strace

It is time to bid our friend strace a fond farewell as he doesn't have what it takes to show us what stat is doing. For that we need to look into the standard library, or as it is commonly known, libc.

The libc code provides a common API for UNIX programs, and a portion of that API is the system calls. These are functions that provide a way for a programmer to ask the kernel for a resource that is managed by the kernel, including the resource we're interested in: the filesystem. The code we'd like to look at is for the system call stat. However, because kernels are very dependent on the hardware architecture they run on, and libc needs to talk to the kernel, much of the code you'll find in the libc source organized by architecture. This makes finding the code for stat tricky; if we look in io/stat.c we see basically a single line of code that calls a function called __xstat. If we find . -name xstat.c we'll see that we want ./sysdeps/unix/sysv/linux/i386/xstat.c, which is the implementation of stat for Linux on i386.

The code in xstat.c that isn't a reference to a C #include looks like:

return INLINE_SYSCALL (stat, 2, CHECK_STRING (name), CHECK_1 ((struct kernel_stat *) buf));

And:

result = INLINE_SYSCALL (stat64, 2, CHECK_STRING (name), __ptrvalue (&buf64));

Reading the comments in the code we can see that stat64is for 64-bit platforms. We'll stick to 32-bits for now, but either way we need to figure out what INLINE_SYSCALL is. A convention in C programming is that FUNCTIONS IN ALL CAPS are pre-processor macros, which means you can typically find out what those macros are by grep'ing for define <macroname>:

adamf@kid-charlemagne:/usr/src/eglibc-2.10.1/sysdeps/unix/sysv/linux/i386$ grep -n "define INLINE_SYSCALL" *
sysdep.h:348:#define INLINE_SYSCALL(name, nr, args...) \

At first, the code we find at line 348 in sysdep.h looks confusing:

#define INLINE_SYSCALL(name, nr, args...) \ 
({                                                                          \ 
    unsigned int resultvar = INTERNAL_SYSCALL (name, , nr, args);             \ 
    if (__builtin_expect (INTERNAL_SYSCALL_ERROR_P (resultvar, ), 0))         \ 
    {                                                                       \ 
        __set_errno (INTERNAL_SYSCALL_ERRNO (resultvar, ));                   \ 
        resultvar = 0xffffffff;                                               \ 
    }                                                                       \ 
    (int) resultvar; })

Looking at the code the call to INTERNAL_SYSCALL stands out - it appears that all INLINE_SYSCALL is doing is calling INTERNAL_SYSCALL. Conveniently we can scroll down in sysdep.h to find the definition of INTERNAL_SYSCALL:

/* Define a macro which expands inline into the wrapper code for a system
call.  This use is for internal calls that do not need to handle errors
normally.  It will never touch errno.  This returns just what the kernel
gave back.

The _NCS variant allows non-constant syscall numbers but it is not
possible to use more than four parameters.  */
#undef INTERNAL_SYSCALL
#ifdef I386_USE_SYSENTER
# ifdef SHARED
#  define INTERNAL_SYSCALL(name, err, nr, args...) \

... but it appears to define INTERNAL_SYSCALL a few times, and I'm not sure which one is actually used.

A good practice in a situation like this is to stop looking at the code and instead take some time to understand the concept the code is trying to implement. Googling for something like i386 system calls linux gets us a to (Implementing A System Call On i386 Linux)[http://tldp.org/HOWTO/html_single/Implement-Sys-Call-Linux-2.6-i386/] which says:

A system call executes in the kernel mode. Every system call has a number associated with it. This number is passed to the kernel and that's how the kernel knows which system call was made. When a user program issues a system call, it is actually calling a library routine. The library routine issues a trap to the Linux operating system by executing INT 0x80 assembly instruction. It also passes the system call number to the kernel using the EAX register. The arguments of the system call are also passed to the kernel using other registers (EBX, ECX, etc.). The kernel executes the system call and returns the result to the user program using a register. If the system call needs to supply the user program with large amounts of data, it will use another mechanism (e.g., copy_to_user call).

Okay, so I think the implementation of INTERNAL_SYSCALL we'll want will have 0x80 in it and some assembly code that puts stuff in the eax register (newer x86 machines can use sysenter instead of int 0x80 to make syscalls). Line 419 in sysdep.h does the trick:

# define INTERNAL_SYSCALL(name, err, nr, args...) \ 
({                                                                          \ 
    register unsigned int resultvar;                                          \ 
    EXTRAVAR_##nr                                                             \ 
    asm volatile (                                                            \ 
    LOADARGS_##nr                                                             \ 
    "movl %1, %%eax\n\t"                                                      \ 
    "int $0x80\n\t"                                                           \ 
    RESTOREARGS_##nr                                                          \ 
    : "=a" (resultvar)                                                        \ 
    : "i" (__NR_##name) ASMFMT_##nr(args) : "memory", "cc");                  \ 
    (int) resultvar; })

If we go back to xstat.c we see that the name we pass to INTERNAL_SYSCALL is stat, and in the code above the name argument will expand from __NR_##name to __NR_stat. The web page we found describing syscalls says that syscalls are represented by a number, so there has to be some piece of code that turns __NR_stat into a number. However, when I grep through all of the libc6 source I can't find any definition of __NR_stat for i386.

It turns out that the code that translates __NR_stat into a number is inside the Linux kernel:

adamf@kid-charlemagne:/usr/src/linux-source-2.6.31$ find . | grep x86 | xargs grep -n "define __NR_stat"
./arch/x86/include/asm/unistd_64.h:23:#define __NR_stat             4
./arch/x86/include/asm/unistd_64.h:309:#define __NR_statfs              137
./arch/x86/include/asm/unistd_32.h:107:#define __NR_statfs       99
./arch/x86/include/asm/unistd_32.h:114:#define __NR_stat        106
./arch/x86/include/asm/unistd_32.h:203:#define __NR_stat64      195
./arch/x86/include/asm/unistd_32.h:276:#define __NR_statfs64        268

The Amulet Of Yendor: Inside The Kernel

The syscall number definitions being inside the kernel makes sense, as the kernel is the owner of the syscall API and as such will have the final say on what numbers get assigned to each syscall. As we're running on 32-bit Linux, it appears the syscall number that libc is going to put in eax is 106.

The table in unistd_32.h is great (look at all those syscalls!) but it doesn't tell us where the code for handling a call to stat actually lives in the kernel. find is our friend again:

adamf@kid-charlemagne:/usr/src/linux-source-2.6.31$ find . -name stat.c
./fs/stat.c
./fs/proc/stat.c

Well that was easy. Opening up fs/stat.c we find what we're looking for:

SYSCALL_DEFINE2(stat, char __user *, filename, struct __old_kernel_stat __user *, statbuf)
{
        struct kstat stat;
        int error;

        error = vfs_stat(filename, &stat);
        if (error)
                return error;

        return cp_old_stat(&stat, statbuf);
}

Looks like this just a wrapper around vfs_stat, which is also in stat.c and is a wrapper around vfs_statat, which again is in stat.c and is wrapper around two functions, user_path_at() and vfs_getattr(). We'll ignore user_path_at() for now (it figures out if the file exists) and instead follow vfs_getattr():

int vfs_getattr(struct vfsmount *mnt, struct dentry *dentry, struct kstat *stat)
{
        struct inode *inode = dentry->d_inode;
        int retval;

        retval = security_inode_getattr(mnt, dentry);
        if (retval)
                return retval;

        if (inode->i_op->getattr)
                return inode->i_op->getattr(mnt, dentry, stat);

        generic_fillattr(inode, stat);
        return 0;
}

One thing that is helpful to do in a case like is to look back at any documentation I have on the function whose implementation I'm tracking down, which in this case is the library call to stat. Back to man 2 stat we see:

   All of these system calls return a stat structure, which contains the following fields:

       struct stat {
           dev_t     st_dev;     /* ID of device containing file */
           ino_t     st_ino;     /* inode number */
           mode_t    st_mode;    /* protection */
           nlink_t   st_nlink;   /* number of hard links */
           uid_t     st_uid;     /* user ID of owner */
           gid_t     st_gid;     /* group ID of owner */
           dev_t     st_rdev;    /* device ID (if special file) */
           off_t     st_size;    /* total size, in bytes */
           blksize_t st_blksize; /* blocksize for file system I/O */
           blkcnt_t  st_blocks;  /* number of 512B blocks allocated */
           time_t    st_atime;   /* time of last access */
           time_t    st_mtime;   /* time of last modification */
           time_t    st_ctime;   /* time of last status change */
       };

So our vfs_getattr function is trying to fill out these fields, which must be in the struct kstat *stat argument to vfs_getattr. vfs_getattr tries to fill out the stat struct in two ways:

    if (inode->i_op->getattr)
            return inode->i_op->getattr(mnt, dentry, stat);

    generic_fillattr(inode, stat);

In the first attempt to fill stat, vfs_getattr checks to see if this inode struct has a special function defined to fill the stat structure. Each inode has an i_op struct which can have a getattr function, if needed. This getattr function is not defined in fs.h but rather is defined by the specific file system the inode is on. This makes good sense as it allows the application programmer to call libc's stat without caring if the underlying file system is ext2, ext3, NTFS, NFS, etc. This abstraction layer is called the 'Virtual File System' and is why the syscall above is prefixed with 'vfs'.

Some filesystems, like NFS, implement a specific getattr handler, but the filesystem I'm running (ext3) does not. In the case where there is no special getattr function defined vfs_getattr will call generic_fillattr (helpfully defined in stat.c) which simply copies the relevant data from the inode struct to the stat struct:

void generic_fillattr(struct inode *inode, struct kstat *stat)
{
        stat->dev = inode->i_sb->s_dev;
        stat->ino = inode->i_ino;
        stat->mode = inode->i_mode;
        stat->nlink = inode->i_nlink;
        stat->uid = inode->i_uid;
        stat->gid = inode->i_gid;
        stat->rdev = inode->i_rdev;
        stat->atime = inode->i_atime;
        stat->mtime = inode->i_mtime;
        stat->ctime = inode->i_ctime;
        stat->size = i_size_read(inode);
        stat->blocks = inode->i_blocks;
        stat->blksize = (1 << inode->i_blkbits);
}

If you squint a little bit at this struct you'll see all the fields you can get out of a single ls command! Our adventure into the kernel has yielded fruit.

Just One More Turn...

If you'd like to keep going, the next thing to figure out is how the inode struct gets populated (hint: ext3_iget) and updated, and from there figure out how the kernel reads that data from the block device (and then how the block device talks to the disk controller, and how the disk controller finds the data on the disk, and so on).

I hope this has been instructive. Digging through the actual source code to a program isn't as easy as reading a summary of how something works, but it is more rewarding and you'll know how the program actually works. Don't be intimidated by an unknown language or concept! We found our way through the internals of the kernel with strace, find and grep, tools a sysadmin uses every day.

Other Resources