TheLazy.Dev
Portfolio GitHub

Blog

linux |systems |engineering

what happens when … (Part 1)

ineedale

Alex Leonhardt

Posted on September 1, 2019

what happens when … (Part 1)

This is for the curious amongst us, who want to know their limits on system internals and/or (inter)networking knowledge and constantly strive to surpass it.

What happens when I type [www.google.com](http://www.google.com) into the browser address bar and hit enter?

You may have come across the above question already (several times), which is probably why you’re here, reading this! It’s a very broad and very difficult question to answer as there are so many moving parts to this question.

We eventually will get to answer the above question, however, let’s not start off with that quite yet, as it would be far too much to go into it right from the start.

My motivation here is not to provide answers, but to show how I’d approach a question / problem like this, and in the process maybe learn a thing or two (or many), but also help you understand a few things better / or in more detail.

So let’s start small and “simple” ..

What happens when I type ls -l into a shell prompt and hit enter?

It’s probably a good idea to stop reading here for a minute and actually think about it and extrapolate what would/could be happening, based on your experience and assumptions, in as much detail as you can..

… just a little longer …

Rather than going ahead and just listing all the things that are happening, I’d like to record how I approach this question (or problem); don’t take this as a step-by-step guide or limit yourself how to approach it, this is how I would do this.

So let’s get started ..

For the record, I’m using a Virtualbox VM running Debian Jessie (8.x) with latest updates applied as of 10/10/2017.

I guess the most obvious first thing to do is to just “execute” the command

$ ls -l

what does it return ?

A directory listing, in the long format, containing various details about every directory and file in it..

root@debian:/var/cache# ls -l
total 28
drwxr-xr-x 3 root root 4096 Oct 10 22:12 apt
drwxr-xr-x 2 root root 4096 Oct 10 22:04 debconf
drwxr-xr-x 2 root root 4096 Jul 3 2015 dictionaries-common
drwxr-xr-x 2 root root 4096 Oct 10 22:03 fontconfig
drwx------ 2 root root 4096 Oct 10 22:04 ldconfig
drwxr-sr-x 32 man root 4096 Oct 10 22:12 man
drwxr-xr-x 2 root root 4096 Apr 23 2014 modass

Based on the above output, we’re in the directory /var/cache, we see the directory/file permissions, the owner, the group, the size (default seems to be set to 4k), last modification date/time and finally the name itself.

That’s quite a bit of information there already, we can make some guesses of what happened, but they’re not going to be very detailed. Some system call that got the current directory, some others got the modification time for every file/directory, etc. So what do we do next / where do we look?

Experience tells me that, if I wanted to see what an application is actually “doing”, I use a tool called strace — running anything with strace requires you to have root permissions (sudo should do). I can’t really remember how I came across it, probably some many many moons ago, some more senior person told me about it I guess.

Anyway, what strace does is trace these system calls that your application is doing (in this case the /bin/ls program) and print them to stdout.

This is how a strace of ls -l actually looks like

root@debian:/var/cache# strace ls -l
execve("/bin/ls", ["ls", "-l"], [/\* 20 vars \*/]) = 0
brk(0) = 0x785000
access("/etc/ld.so.nohwcap", F\_OK) = -1 ENOENT (No such file or directory)
mmap(NULL, 8192, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_ANONYMOUS, -1, 0) = 0x7f420b3b2000
access("/etc/ld.so.preload", R\_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O\_RDONLY|O\_CLOEXEC) = 3
fstat(3, {st\_mode=S\_IFREG|0644, st\_size=23259, ...}) = 0
mmap(NULL, 23259, PROT\_READ, MAP\_PRIVATE, 3, 0) = 0x7f420b3ac000
close(3) = 0
access("/etc/ld.so.nohwcap", F\_OK) = -1 ENOENT (No such file or directory)
open("/lib/x86\_64-linux-gnu/libselinux.so.1", O\_RDONLY|O\_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0\>\0\1\0\0\0\20c\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st\_mode=S\_IFREG|0644, st\_size=142728, ...}) = 0
mmap(NULL, 2246896, PROT\_READ|PROT\_EXEC, MAP\_PRIVATE|MAP\_DENYWRITE, 3, 0) = 0x7f420af6f000
mprotect(0x7f420af90000, 2097152, PROT\_NONE) = 0
mmap(0x7f420b190000, 8192, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_FIXED|MAP\_DENYWRITE, 3, 0x21000) = 0x7f420b190000
mmap(0x7f420b192000, 6384, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_FIXED|MAP\_ANONYMOUS, -1, 0) = 0x7f420b192000
close(3) = 0
access("/etc/ld.so.nohwcap", F\_OK) = -1 ENOENT (No such file or directory)
open("/lib/x86\_64-linux-gnu/libacl.so.1", O\_RDONLY|O\_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0\>\0\1\0\0\0\200\37\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st\_mode=S\_IFREG|0644, st\_size=35288, ...}) = 0
mmap(NULL, 2130592, PROT\_READ|PROT\_EXEC, MAP\_PRIVATE|MAP\_DENYWRITE, 3, 0) = 0x7f420ad66000
mprotect(0x7f420ad6e000, 2093056, PROT\_NONE) = 0
mmap(0x7f420af6d000, 8192, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_FIXED|MAP\_DENYWRITE, 3, 0x7000) = 0x7f420af6d000
close(3) = 0
access("/etc/ld.so.nohwcap", F\_OK) = -1 ENOENT (No such file or directory)
open("/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\0P\34\2\0\0\0\0\0"..., 832) = 832
fstat(3, {st\_mode=S\_IFREG|0755, st\_size=1738176, ...}) = 0
mmap(NULL, 4096, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_ANONYMOUS, -1, 0) = 0x7f420b3ab000
mmap(NULL, 3844640, PROT\_READ|PROT\_EXEC, MAP\_PRIVATE|MAP\_DENYWRITE, 3, 0) = 0x7f420a9bb000
mprotect(0x7f420ab5c000, 2097152, PROT\_NONE) = 0
mmap(0x7f420ad5c000, 24576, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_FIXED|MAP\_DENYWRITE, 3, 0x1a1000) = 0x7f420ad5c000
mmap(0x7f420ad62000, 14880, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_FIXED|MAP\_ANONYMOUS, -1, 0) = 0x7f420ad62000
close(3) = 0
access("/etc/ld.so.nohwcap", F\_OK) = -1 ENOENT (No such file or directory)
open("/lib/x86\_64-linux-gnu/libpcre.so.3", O\_RDONLY|O\_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0\>\0\1\0\0\0\20\27\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st\_mode=S\_IFREG|0644, st\_size=448440, ...}) = 0
mmap(NULL, 2543976, PROT\_READ|PROT\_EXEC, MAP\_PRIVATE|MAP\_DENYWRITE, 3, 0) = 0x7f420a74d000
mprotect(0x7f420a7b9000, 2097152, PROT\_NONE) = 0
mmap(0x7f420a9b9000, 8192, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_FIXED|MAP\_DENYWRITE, 3, 0x6c000) = 0x7f420a9b9000
close(3) = 0
access("/etc/ld.so.nohwcap", F\_OK) = -1 ENOENT (No such file or directory)
open("/lib/x86\_64-linux-gnu/libdl.so.2", O\_RDONLY|O\_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0\>\0\1\0\0\0\320\16\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st\_mode=S\_IFREG|0644, st\_size=14664, ...}) = 0
mmap(NULL, 2109712, PROT\_READ|PROT\_EXEC, MAP\_PRIVATE|MAP\_DENYWRITE, 3, 0) = 0x7f420a549000
mprotect(0x7f420a54c000, 2093056, PROT\_NONE) = 0
mmap(0x7f420a74b000, 8192, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_FIXED|MAP\_DENYWRITE, 3, 0x2000) = 0x7f420a74b000
close(3) = 0
access("/etc/ld.so.nohwcap", F\_OK) = -1 ENOENT (No such file or directory)
open("/lib/x86\_64-linux-gnu/libattr.so.1", O\_RDONLY|O\_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0\>\0\1\0\0\0\320\23\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st\_mode=S\_IFREG|0644, st\_size=18640, ...}) = 0
mmap(NULL, 4096, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_ANONYMOUS, -1, 0) = 0x7f420b3aa000
mmap(NULL, 2113912, PROT\_READ|PROT\_EXEC, MAP\_PRIVATE|MAP\_DENYWRITE, 3, 0) = 0x7f420a344000
mprotect(0x7f420a348000, 2093056, PROT\_NONE) = 0
mmap(0x7f420a547000, 8192, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_FIXED|MAP\_DENYWRITE, 3, 0x3000) = 0x7f420a547000
close(3) = 0
access("/etc/ld.so.nohwcap", F\_OK) = -1 ENOENT (No such file or directory)
open("/lib/x86\_64-linux-gnu/libpthread.so.0", O\_RDONLY|O\_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0\>\0\1\0\0\0\320n\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st\_mode=S\_IFREG|0755, st\_size=137384, ...}) = 0
mmap(NULL, 2213008, PROT\_READ|PROT\_EXEC, MAP\_PRIVATE|MAP\_DENYWRITE, 3, 0) = 0x7f420a127000
mprotect(0x7f420a13f000, 2093056, PROT\_NONE) = 0
mmap(0x7f420a33e000, 8192, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_FIXED|MAP\_DENYWRITE, 3, 0x17000) = 0x7f420a33e000
mmap(0x7f420a340000, 13456, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_FIXED|MAP\_ANONYMOUS, -1, 0) = 0x7f420a340000
close(3) = 0
mmap(NULL, 4096, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_ANONYMOUS, -1, 0) = 0x7f420b3a9000
mmap(NULL, 8192, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_ANONYMOUS, -1, 0) = 0x7f420b3a7000
arch\_prctl(ARCH\_SET\_FS, 0x7f420b3a7800) = 0
mprotect(0x7f420ad5c000, 16384, PROT\_READ) = 0
mprotect(0x7f420a33e000, 4096, PROT\_READ) = 0
mprotect(0x7f420a547000, 4096, PROT\_READ) = 0
mprotect(0x7f420a74b000, 4096, PROT\_READ) = 0
mprotect(0x7f420a9b9000, 4096, PROT\_READ) = 0
mprotect(0x7f420af6d000, 4096, PROT\_READ) = 0
mprotect(0x7f420b190000, 4096, PROT\_READ) = 0
mprotect(0x61b000, 4096, PROT\_READ) = 0
mprotect(0x7f420b3b4000, 4096, PROT\_READ) = 0
munmap(0x7f420b3ac000, 23259) = 0
set\_tid\_address(0x7f420b3a7ad0) = 26019
set\_robust\_list(0x7f420b3a7ae0, 24) = 0
rt\_sigaction(SIGRTMIN, {0x7f420a12d9b0, [], SA\_RESTORER|SA\_SIGINFO, 0x7f420a136890}, NULL, 8) = 0
rt\_sigaction(SIGRT\_1, {0x7f420a12da40, [], SA\_RESTORER|SA\_RESTART|SA\_SIGINFO, 0x7f420a136890}, NULL, 8) = 0
rt\_sigprocmask(SIG\_UNBLOCK, [RTMIN RT\_1], NULL, 8) = 0
getrlimit(RLIMIT\_STACK, {rlim\_cur=8192\*1024, rlim\_max=RLIM64\_INFINITY}) = 0
statfs("/sys/fs/selinux", 0x7ffd512871e0) = -1 ENOENT (No such file or directory)
statfs("/selinux", 0x7ffd512871e0) = -1 ENOENT (No such file or directory)
brk(0) = 0x785000
brk(0x7a6000) = 0x7a6000
open("/proc/filesystems", O\_RDONLY) = 3
fstat(3, {st\_mode=S\_IFREG|0444, st\_size=0, ...}) = 0
mmap(NULL, 4096, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_ANONYMOUS, -1, 0) = 0x7f420b3b1000
read(3, "nodev\tsysfs\nnodev\trootfs\nnodev\tr"..., 1024) = 317
read(3, "", 1024) = 0
close(3) = 0
munmap(0x7f420b3b1000, 4096) = 0
open("/usr/lib/locale/locale-archive", O\_RDONLY|O\_CLOEXEC) = 3
fstat(3, {st\_mode=S\_IFREG|0644, st\_size=1607712, ...}) = 0
mmap(NULL, 1607712, PROT\_READ, MAP\_PRIVATE, 3, 0) = 0x7f420b21e000
close(3) = 0
open("/usr/share/locale/locale.alias", O\_RDONLY|O\_CLOEXEC) = 3
fstat(3, {st\_mode=S\_IFREG|0644, st\_size=2492, ...}) = 0
mmap(NULL, 4096, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_ANONYMOUS, -1, 0) = 0x7f420b3b1000
read(3, "# Locale name alias data base.\n#"..., 4096) = 2492
read(3, "", 4096) = 0
close(3) = 0
munmap(0x7f420b3b1000, 4096) = 0
open("/usr/lib/locale/en\_GB.UTF-8/LC\_CTYPE", O\_RDONLY|O\_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en\_GB.utf8/LC\_CTYPE", O\_RDONLY|O\_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en\_GB/LC\_CTYPE", O\_RDONLY|O\_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en.UTF-8/LC\_CTYPE", O\_RDONLY|O\_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en.utf8/LC\_CTYPE", O\_RDONLY|O\_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en/LC\_CTYPE", O\_RDONLY|O\_CLOEXEC) = -1 ENOENT (No such file or directory)
ioctl(1, SNDCTL\_TMR\_TIMEBASE or SNDRV\_TIMER\_IOCTL\_NEXT\_DEVICE or TCGETS, {B38400 opost isig icanon echo ...}) = 0
ioctl(1, TIOCGWINSZ, {ws\_row=57, ws\_col=238, ws\_xpixel=0, ws\_ypixel=0}) = 0
openat(AT\_FDCWD, ".", O\_RDONLY|O\_NONBLOCK|O\_DIRECTORY|O\_CLOEXEC) = 3
getdents(3, /\* 9 entries \*/, 32768) = 264
lstat("debconf", {st\_mode=S\_IFDIR|0755, st\_size=4096, ...}) = 0
lgetxattr("debconf", "security.selinux", 0x785eb0, 255) = -1 ENODATA (No data available)
getxattr("debconf", "system.posix\_acl\_access", 0x0, 0) = -1 ENODATA (No data available)
getxattr("debconf", "system.posix\_acl\_default", 0x0, 0) = -1 ENODATA (No data available)
socket(PF\_LOCAL, SOCK\_STREAM|SOCK\_CLOEXEC|SOCK\_NONBLOCK, 0) = 4
connect(4, {sa\_family=AF\_LOCAL, sun\_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(4) = 0
socket(PF\_LOCAL, SOCK\_STREAM|SOCK\_CLOEXEC|SOCK\_NONBLOCK, 0) = 4
connect(4, {sa\_family=AF\_LOCAL, sun\_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(4) = 0
open("/etc/nsswitch.conf", O\_RDONLY|O\_CLOEXEC) = 4
fstat(4, {st\_mode=S\_IFREG|0644, st\_size=497, ...}) = 0
mmap(NULL, 4096, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_ANONYMOUS, -1, 0) = 0x7f420b3b1000
read(4, "# /etc/nsswitch.conf\n#\n# Example"..., 4096) = 497
read(4, "", 4096) = 0
close(4) = 0
munmap(0x7f420b3b1000, 4096) = 0
open("/etc/ld.so.cache", O\_RDONLY|O\_CLOEXEC) = 4
fstat(4, {st\_mode=S\_IFREG|0644, st\_size=23259, ...}) = 0
mmap(NULL, 23259, PROT\_READ, MAP\_PRIVATE, 4, 0) = 0x7f420b3ac000
close(4) = 0
access("/etc/ld.so.nohwcap", F\_OK) = -1 ENOENT (No such file or directory)
open("/lib/x86\_64-linux-gnu/libnss\_compat.so.2", O\_RDONLY|O\_CLOEXEC) = 4
read(4, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0\>\0\1\0\0\0\260\23\0\0\0\0\0\0"..., 832) = 832
fstat(4, {st\_mode=S\_IFREG|0644, st\_size=31632, ...}) = 0
mmap(NULL, 2126976, PROT\_READ|PROT\_EXEC, MAP\_PRIVATE|MAP\_DENYWRITE, 4, 0) = 0x7f4209f1f000
mprotect(0x7f4209f26000, 2093056, PROT\_NONE) = 0
mmap(0x7f420a125000, 8192, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_FIXED|MAP\_DENYWRITE, 4, 0x6000) = 0x7f420a125000
close(4) = 0
access("/etc/ld.so.nohwcap", F\_OK) = -1 ENOENT (No such file or directory)
open("/lib/x86\_64-linux-gnu/libnsl.so.1", O\_RDONLY|O\_CLOEXEC) = 4
read(4, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0\>\0\1\0\0\0`A\0\0\0\0\0\0"..., 832) = 832
fstat(4, {st\_mode=S\_IFREG|0644, st\_size=89104, ...}) = 0
mmap(NULL, 2194072, PROT\_READ|PROT\_EXEC, MAP\_PRIVATE|MAP\_DENYWRITE, 4, 0) = 0x7f4209d07000
mprotect(0x7f4209d1c000, 2093056, PROT\_NONE) = 0
mmap(0x7f4209f1b000, 8192, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_FIXED|MAP\_DENYWRITE, 4, 0x14000) = 0x7f4209f1b000
mmap(0x7f4209f1d000, 6808, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_FIXED|MAP\_ANONYMOUS, -1, 0) = 0x7f4209f1d000
close(4) = 0
mprotect(0x7f4209f1b000, 4096, PROT\_READ) = 0
mprotect(0x7f420a125000, 4096, PROT\_READ) = 0
munmap(0x7f420b3ac000, 23259) = 0
open("/etc/ld.so.cache", O\_RDONLY|O\_CLOEXEC) = 4
fstat(4, {st\_mode=S\_IFREG|0644, st\_size=23259, ...}) = 0
mmap(NULL, 23259, PROT\_READ, MAP\_PRIVATE, 4, 0) = 0x7f420b3ac000
close(4) = 0
access("/etc/ld.so.nohwcap", F\_OK) = -1 ENOENT (No such file or directory)
open("/lib/x86\_64-linux-gnu/libnss\_nis.so.2", O\_RDONLY|O\_CLOEXEC) = 4
read(4, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0\>\0\1\0\0\0\240!\0\0\0\0\0\0"..., 832) = 832
fstat(4, {st\_mode=S\_IFREG|0644, st\_size=43592, ...}) = 0
mmap(NULL, 2139560, PROT\_READ|PROT\_EXEC, MAP\_PRIVATE|MAP\_DENYWRITE, 4, 0) = 0x7f4209afc000
mprotect(0x7f4209b06000, 2093056, PROT\_NONE) = 0
mmap(0x7f4209d05000, 8192, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_FIXED|MAP\_DENYWRITE, 4, 0x9000) = 0x7f4209d05000
close(4) = 0
access("/etc/ld.so.nohwcap", F\_OK) = -1 ENOENT (No such file or directory)
open("/lib/x86\_64-linux-gnu/libnss\_files.so.2", O\_RDONLY|O\_CLOEXEC) = 4
read(4, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0\>\0\1\0\0\0\240\"\0\0\0\0\0\0"..., 832) = 832
fstat(4, {st\_mode=S\_IFREG|0644, st\_size=47712, ...}) = 0
mmap(NULL, 2144392, PROT\_READ|PROT\_EXEC, MAP\_PRIVATE|MAP\_DENYWRITE, 4, 0) = 0x7f42098f0000
mprotect(0x7f42098fb000, 2093056, PROT\_NONE) = 0
mmap(0x7f4209afa000, 8192, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_FIXED|MAP\_DENYWRITE, 4, 0xa000) = 0x7f4209afa000
close(4) = 0
mprotect(0x7f4209afa000, 4096, PROT\_READ) = 0
mprotect(0x7f4209d05000, 4096, PROT\_READ) = 0
munmap(0x7f420b3ac000, 23259) = 0
open("/etc/passwd", O\_RDONLY|O\_CLOEXEC) = 4
lseek(4, 0, SEEK\_CUR) = 0
fstat(4, {st\_mode=S\_IFREG|0644, st\_size=1488, ...}) = 0
mmap(NULL, 1488, PROT\_READ, MAP\_SHARED, 4, 0) = 0x7f420b3b1000
lseek(4, 1488, SEEK\_SET) = 1488
munmap(0x7f420b3b1000, 1488) = 0
close(4) = 0
socket(PF\_LOCAL, SOCK\_STREAM|SOCK\_CLOEXEC|SOCK\_NONBLOCK, 0) = 4
connect(4, {sa\_family=AF\_LOCAL, sun\_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(4) = 0
socket(PF\_LOCAL, SOCK\_STREAM|SOCK\_CLOEXEC|SOCK\_NONBLOCK, 0) = 4
connect(4, {sa\_family=AF\_LOCAL, sun\_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(4) = 0
open("/etc/group", O\_RDONLY|O\_CLOEXEC) = 4
lseek(4, 0, SEEK\_CUR) = 0
fstat(4, {st\_mode=S\_IFREG|0644, st\_size=748, ...}) = 0
mmap(NULL, 748, PROT\_READ, MAP\_SHARED, 4, 0) = 0x7f420b3b1000
lseek(4, 748, SEEK\_SET) = 748
munmap(0x7f420b3b1000, 748) = 0
close(4) = 0
lstat("fontconfig", {st\_mode=S\_IFDIR|0755, st\_size=4096, ...}) = 0
lgetxattr("fontconfig", "security.selinux", 0x7968e0, 255) = -1 ENODATA (No data available)
getxattr("fontconfig", "system.posix\_acl\_access", 0x0, 0) = -1 ENODATA (No data available)
getxattr("fontconfig", "system.posix\_acl\_default", 0x0, 0) = -1 ENODATA (No data available)
lstat("dictionaries-common", {st\_mode=S\_IFDIR|0755, st\_size=4096, ...}) = 0
lgetxattr("dictionaries-common", "security.selinux", 0x796900, 255) = -1 ENODATA (No data available)
getxattr("dictionaries-common", "system.posix\_acl\_access", 0x0, 0) = -1 ENODATA (No data available)
getxattr("dictionaries-common", "system.posix\_acl\_default", 0x0, 0) = -1 ENODATA (No data available)
lstat("man", {st\_mode=S\_IFDIR|S\_ISGID|0755, st\_size=4096, ...}) = 0
lgetxattr("man", "security.selinux", 0x796920, 255) = -1 ENODATA (No data available)
getxattr("man", "system.posix\_acl\_access", 0x0, 0) = -1 ENODATA (No data available)
getxattr("man", "system.posix\_acl\_default", 0x0, 0) = -1 ENODATA (No data available)
open("/etc/passwd", O\_RDONLY|O\_CLOEXEC) = 4
lseek(4, 0, SEEK\_CUR) = 0
fstat(4, {st\_mode=S\_IFREG|0644, st\_size=1488, ...}) = 0
mmap(NULL, 1488, PROT\_READ, MAP\_SHARED, 4, 0) = 0x7f420b3b1000
lseek(4, 1488, SEEK\_SET) = 1488
munmap(0x7f420b3b1000, 1488) = 0
close(4) = 0
lstat("modass", {st\_mode=S\_IFDIR|0755, st\_size=4096, ...}) = 0
lgetxattr("modass", "security.selinux", 0x796960, 255) = -1 ENODATA (No data available)
getxattr("modass", "system.posix\_acl\_access", 0x0, 0) = -1 ENODATA (No data available)
getxattr("modass", "system.posix\_acl\_default", 0x0, 0) = -1 ENODATA (No data available)
lstat("ldconfig", {st\_mode=S\_IFDIR|0700, st\_size=4096, ...}) = 0
lgetxattr("ldconfig", "security.selinux", 0x796980, 255) = -1 ENODATA (No data available)
getxattr("ldconfig", "system.posix\_acl\_access", 0x0, 0) = -1 ENODATA (No data available)
getxattr("ldconfig", "system.posix\_acl\_default", 0x0, 0) = -1 ENODATA (No data available)
lstat("apt", {st\_mode=S\_IFDIR|0755, st\_size=4096, ...}) = 0
lgetxattr("apt", "security.selinux", 0x7969a0, 255) = -1 ENODATA (No data available)
getxattr("apt", "system.posix\_acl\_access", 0x0, 0) = -1 ENODATA (No data available)
getxattr("apt", "system.posix\_acl\_default", 0x0, 0) = -1 ENODATA (No data available)
getdents(3, /\* 0 entries \*/, 32768) = 0
close(3) = 0
fstat(1, {st\_mode=S\_IFCHR|0600, st\_rdev=makedev(136, 0), ...}) = 0
mmap(NULL, 4096, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_ANONYMOUS, -1, 0) = 0x7f420b3b1000
write(1, "total 28\n", 9total 28
) = 9
open("/etc/localtime", O\_RDONLY|O\_CLOEXEC) = 3
fstat(3, {st\_mode=S\_IFREG|0644, st\_size=1892, ...}) = 0
fstat(3, {st\_mode=S\_IFREG|0644, st\_size=1892, ...}) = 0
mmap(NULL, 4096, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_ANONYMOUS, -1, 0) = 0x7f420b3b0000
read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0\0\0\0"..., 4096) = 1892
lseek(3, -1217, SEEK\_CUR) = 675
read(3, "TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\6\0\0\0\6\0\0\0\0"..., 4096) = 1217
close(3) = 0
munmap(0x7f420b3b0000, 4096) = 0
write(1, "drwxr-xr-x 3 root root 4096 Oct"..., 46drwxr-xr-x 3 root root 4096 Oct 10 22:12 apt
) = 46
stat("/etc/localtime", {st\_mode=S\_IFREG|0644, st\_size=1892, ...}) = 0
write(1, "drwxr-xr-x 2 root root 4096 Oct"..., 50drwxr-xr-x 2 root root 4096 Oct 10 22:23 debconf
) = 50
stat("/etc/localtime", {st\_mode=S\_IFREG|0644, st\_size=1892, ...}) = 0
write(1, "drwxr-xr-x 2 root root 4096 Jul"..., 62drwxr-xr-x 2 root root 4096 Jul 3 2015 dictionaries-common
) = 62
stat("/etc/localtime", {st\_mode=S\_IFREG|0644, st\_size=1892, ...}) = 0
write(1, "drwxr-xr-x 2 root root 4096 Oct"..., 53drwxr-xr-x 2 root root 4096 Oct 10 22:03 fontconfig
) = 53
stat("/etc/localtime", {st\_mode=S\_IFREG|0644, st\_size=1892, ...}) = 0
write(1, "drwx------ 2 root root 4096 Oct"..., 51drwx------ 2 root root 4096 Oct 10 22:04 ldconfig
) = 51
stat("/etc/localtime", {st\_mode=S\_IFREG|0644, st\_size=1892, ...}) = 0
write(1, "drwxr-sr-x 32 man root 4096 Oct"..., 46drwxr-sr-x 32 man root 4096 Oct 10 22:12 man
) = 46
stat("/etc/localtime", {st\_mode=S\_IFREG|0644, st\_size=1892, ...}) = 0
write(1, "drwxr-xr-x 2 root root 4096 Apr"..., 49drwxr-xr-x 2 root root 4096 Apr 23 2014 modass
) = 49
close(1) = 0
munmap(0x7f420b3b1000, 4096) = 0
close(2) = 0
exit\_group(0) = ?
+++ exited with 0 +++

That’s not very readable, maybe just try it yourself, on a Vagrant box or some other Linux install; make sure to install the strace package and just go to /var/cache and execute strace ls -l .

Okay, that’s a lot of stuff that’s going on there — let’s start at the top and skip over a few bits whilst working our way down

root@debian:/var/cache# strace ls -l
execve("/bin/ls", ["ls", "-l"], [/\* 20 vars \*/]) = 0
brk(0) = 0x785000
access("/etc/ld.so.nohwcap", F\_OK) = -1 ENOENT (No such file or directory)
mmap(NULL, 8192, PROT\_READ|PROT\_WRITE, MAP\_PRIVATE|MAP\_ANONYMOUS, -1, 0) = 0x7f420b3b2000
access("/etc/ld.so.preload", R\_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O\_RDONLY|O\_CLOEXEC) = 3
fstat(3, {st\_mode=S\_IFREG|0644, st\_size=23259, ...}) = 0
mmap(NULL, 23259, PROT\_READ, MAP\_PRIVATE, 3, 0) = 0x7f420b3ac000
close(3) = 0

So there are a couple of system calls we can see already

  • execve (execute /bin/ls with argument l)
  • brk
  • mmap (reserve 8k of memory with address 0x7f420b3b2000)
  • open (reads the file /etc/ld.so.cache with file descriptor 3)
  • fstat (file stats like permission, size)
  • mmap (read file with descriptor 3into 0x7f420b3b2000)
  • close (close the file with fd 3)

It’ll be very beneficial to have a list of what all the above means, maybe this can be of some help https://golang.org/pkg/syscall/#pkg-constants

It may also be worth asking… is there anything that might be happening before execve? Are there other exec calls that can / would / could be made, and if so, why is execve used or what is the difference between them?

Note: I’ve linked to execve, exec, etc. system calls so you can review that documentation and answer the questions yourself. I find it more useful this way as you may be reading additional information that I’d skip over. If you are asking yourself “what if…” after reading.. then keep digging until that question is also answered (hopefully by some relevant piece of documentation).

As we know, hopefully, a new process “inherits” all of the current shell's environment variables, how is that possible, and .. when a program exits, why does it not also close its calling shell, since “it replaces” the shell with the running program?

It’s not particularly obvious, but at least bash shell, before running execve runs fork which duplicates the shell and all of its current state (with some exceptions and resets). But why can’t we see that in our strace? Because strace is executing our program, and the shell already called fork to start strace. A important detail about fork() is at the bottom of the documentation.

Under Linux, fork() is implemented using copy-on-write* pages, so the only penalty that it incurs is the time and memory required to duplicate the parent’s page tables, and to create a unique task structure for the child.

Think about what this could mean for resource consumptions on a Linux host?

So how did (other) people “find out” that fork() is called by the shell before execve? I believe (at least at times) a good way to find out what happens is to look at the source code, since our tracing tool cannot trace what happens in the shell (I’m assuming you’re using bash).

Bash source code is here : https://ftp.gnu.org/gnu/bash/


...

/*
The meaty part of all the executions. We have to start hacking the real execution of commands here. Fork a process, set things up, execute the command.
*/

static int
execute_simple_command (simple_command, pipe_in, pipe_out, async, fds_to_close)

SIMPLE_COM *simple_command;
int pipe_in, pipe_out, async;
struct fd_bitmap *fds_to_close;

...

A small snippet from execute_cmd.c from the bash source code, I believe the function comment explains what is happening when executing a command without necessarily needing to look at (and understand) the code itself.

The actual fork() is hidden in jobs.c though …

...

/* 
Create the child, handle severe errors. Retry on EAGAIN. 
*/

while ((pid = fork ()) < 0 && errno == EAGAIN && forksleep < FORKSLEEP_MAX)
 {

...

You might ask yourself, are there other things that happen before executing a command? Like fork(), they might not be able to be traced using strace.

End of Part 1

...

In Part 2, I’ll continue with the last question and if time permits walk further down the strace done in Part 1.

💖 💪 🙅 🚩
ineedale
Alex Leonhardt

Posted on September 1, 2019

Join Our Newsletter. No Spam, Only the good stuff.

Sign up to receive the latest update from our blog.

Related

what happens when … (Part 1)
linux what happens when … (Part 1)

September 1, 2019