April 12, 2012
1 min read time

Counting syscall in Varnish Cache

Way back when we did a rough count on how many syscalls Varnish uses to deliver a piece of cache content. I think Anders counted seven calls per hit, roughly based on some system counters. I just did a recount, just to see how we are doing. After all, calling the kernel is one of the more expensive things to do in a program. Here is what I found.

Edit: I think the original claim was 7 system calls + 5 locks.

The first two syscalls - the acceptor threads

[pid 26106] poll([{fd=8, events=POLLIN}, {fd=9, events=POLLIN}], 2, ....

[pid 26106] accept(9, <unfinished ...>)

It polls the file descriptors and accepts any connection that has been made. Then the file descriptor is handled over to the designated worker thread that. There is a lock, probably the one on the thread pool, that is set before a worker thread is picked.

[pid 26106] futex(0x7fb7fba9fc1c, FUTEX_WAKE_OP_PRIVATE, 1, 1,...

The worker threads

Then the worker thread takes a couple of locks and does a ioctl of some sort.
[pid 26202] futex(0x7fb835e123a8, FUTEX_WAKE_PRIVATE, 1
[pid 26202] ioctl(12, FIONBIO
[pid 26202] futex(0x6797a0, FUTEX_WAIT_PRIVATE, 2, NULL
[pid 26202] futex(0x6797a0, FUTEX_WAKE_PRIVATE, 1) = 0

Then a poll and then the request is read.

[pid 26202] poll([{fd=12, events=POLLIN}], 1, 50
[pid 26202] read(12, "GET / HTTP/1.0\r\n"..., 32767) = 82

After we got the request there is the small matter of serving it:

[pid 26202] writev(12, [{"HTTP/1.1", 8}, {" ", 1}, {"200", 3}, {" ", 1}, {"OK", 2}, {"\r\n", 2}, {"Server: Apache/2.2.14 (Ubuntu)", 30}, {"\r\n", 2}, {"V

And clean up. Close the connection and lock the thread pool before putting itself back in the pool.

[pid 26202] close(12
[pid 26202] futex(0x7fb7fba9fc1c, FUTEX_WAIT_PRIVATE, 453, NULL

Sum

To sum it up. 3 syscalls in the acceptor thread. 9 in the worker thread. 12 in all.

Edit: Of those 12, 5 are locks. So, 7 + 5 seems still to be the case. :-)