How does 'strace' work?

Question

Recently, I was using mv to move a large amount of files from my hard drive to a flash drive. I forgot to add a verbose flag so I had no idea "where" the move was at and how many transfers remained.

I found the strace utility and decided to use it on my mv process. Using ps -ef | grep mv I was able to find the pid of the process and then ran strace -p [PID]. Here's a sample of what I got:

write(4, "\325\0\0s\1\1\224\0\0\0\0\0109\27\0\0\201\327\0\0\240H:\310xgM\337\274\26\"\273"..., 32768) = 32768
read(3, "\6\3319H\r\207\345\257\301JL)\2601C\t\303\22(\214\353\211\230;{\6\214\355nh@F"..., 32768) = 32768
write(4, "\6\3319H\r\207\345\257\301JL)\2601C\t\303\22(\214\353\211\230;{\6\214\355nh@F"..., 32768) = 32768
read(3, "ZK\301\332\263\214@\177\3352$\374\277];\255\265\364\240d\275\307P\237*\364\23\206\31\306\244\256"..., 32768) = 32768
write(4, "ZK\301\332\263\214@\177\3352$\374\277];\255\265\364\240d\275\307P\237*\364\23\206\31\306\244\256"..., 32768) = 32768
read(3, ".\341\355\32\366\7\365\244\4\4\221{c,$\246]\204\342\261\"\374K\234\264\17\26\346\246\327\347m"..., 32768) = 32768

and then some:

fcntl(3, F_GETFD)                       = 0
fcntl(3, F_SETFD, FD_CLOEXEC)           = 0
fstat(3, {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
fcntl(3, F_GETFL)                       = 0x38800 (flags O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_NOFOLLOW)
fcntl(3, F_SETFD, FD_CLOEXEC)           = 0
fcntl(3, F_DUPFD, 3)                    = 4
fcntl(4, F_GETFD)                       = 0
fcntl(4, F_SETFD, FD_CLOEXEC)           = 0
getdents64(3, /* 4 entries */, 32768)   = 120
getdents64(3, /* 0 entries */, 32768)   = 0
close(3)                                = 0
newfstatat(4, "The Pick of Destiny", {st_mode=S_IFDIR|0755, st_size=4096, ...}, AT_SYMLINK_NOFOLLOW) = 0
openat(4, "The Pick of Destiny", O_RDONLY|O_NOCTTY|O_NONBLOCK|O_DIRECTORY|O_NOFOLLOW) = 3
fcntl(3, F_GETFD)                       = 0
fcntl(3, F_SETFD, FD_CLOEXEC)           = 0
fstat(3, {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
fcntl(3, F_GETFL)                       = 0x38800 (flags O_RDONLY|O_NONBLOCK|O_LARGEFILE|O_DIRECTORY|O_NOFOLLOW)
fcntl(3, F_SETFD, FD_CLOEXEC)           = 0
fcntl(3, F_DUPFD, 3)                    = 5
fcntl(5, F_GETFD)                       = 0
fcntl(5, F_SETFD, FD_CLOEXEC)           = 0
getdents64(3, /* 22 entries */, 32768)  = 1008
getdents64(3, /* 0 entries */, 32768)   = 0
close(3)                                = 0

---

So, what exactly does strace give me? Are these kernel calls? If they are, what do they mean (I know what read and write do but what are those numbers)?

Bonus Question: Is there a way for me to see anything "lower" than what strace shows me? CPU calls maybe?

Answer 1

So, what exactly does strace give me?

What strace is giving you is system calls - calls which are requesting the kernel do something that the process itself cannot do, such as opening files. (e.x. fcntl, close, etc are found in your trace).

If they are, what do they mean (I know what read and write do but what are those numbers)?

fcntl(3, F_GETFD) = 0

Translates into: system call (fcntl) with arguments (3, F_GETFD) which is returning a value (0).

Bonus Question: Is there a way for me to see anything "lower" than what strace shows me? CPU calls maybe?

You mean either 1) CPU interrupts or 2) assembly instructions. I don't know, honestly, but:

1. Watching interrupts fire seems like it wouldn't be that useful.
2. Watching the instructions the processor is executing seems a little low level, and still not that useful. Frankly, if I wanted that, I'd just run my program in an really slow emulator that allows me to watch what assembly is interpreted.

strace has a man page - I suggest you read it if you want details on it's workings.

Answer 2

You have pretty much got the answer right in your original question.

The default behaviour of strace is to report what system calls are being performed for that process, it will also report signals called and what handler handled that signal.

In your example the syscalls being called are at the start of the line: fcntl(), getdents64() close() etc.

The arguments that were passed to those syscalls are shown - often truncated, as the raw data can be kilo/mega/giga Bytes in size) fstat(3, {st_mode=S_IFDIR|0755, st_size=4096, ...}) (the ... donates the truncation). What those value represents varies from syscall to syscall but man will show what they represent (provided you have the basic set of man pages related to the sys calls installed on your system). man 2 fstat will show the programmers manual page for fstat and details the arguments.

And the result of that syscall getdents64(3, /* 22 entries */, 32768) = 1008 1008 in this case. The value of of this result code will be documentated in the man(1) page of the specific syscall being called in the same way arguments are detailed. Note in this case the /* 22 entries */ is another truncation operation by strace, this can be expanded upon with -e abbr=none.

Note that strace is not a universal command, some releases of unix use truss, ktrace and dump to perform similar debugging on a process. You should also take a look at the man page for strace, it comes with some extended options (maybe this gets close your bonus question) such as -i (print the instruction pointer) -v (verbosity) -a (change the location - column - of the result part to see more of the arguments passed to the command) and expression filtering -e.

edit added some notes about other forms argument truncation.