5 ms·
C Runtime Overhead (2015)
- eatonphil 5y agoAwesome post! And (2015) for the title maybe.
- Zababa 5y agoThanks, added!
- josefx 5y ago> I happened to run strace -tt against my solution (which provides microsecond-accurate timing information for syscalls) Weirdly I always found the timing results of strace at under one millisecond generally unreliable, it just seemed to add too much overhead itself. Also making system calls from your own code varies between prohibited and badly supported on most OSes. Some see calls that didn't pass through the system libc as a security issue and will intercept them, while Linux may just silently corrupt your process memory if you try something fancy as the Go team had to find out.
- badsectoracula 5y ago> Also making system calls from your own code varies between prohibited and badly supported on most OSes. This is not the case on Linux though, the official API of the kernel is its system calls, not any specific C library.
- dwattttt 5y agoWhile this is true, the go vs vDSO stack clash corruption highlights that a C ABI that doesn't specify stack usage is under defined. A platforms libc can be written such that it's aware of these limitations.
- badsectoracula 5y agoThis can be said about any wrapper to an underdefined interface, it doesn't make that interface any less official.
- mgaunard 5y agoThat's the difference between precision and accuracy. Having more precision doesn't magically make the data accurate.
- commandlinefan 5y ago> making system calls from your own code varies between prohibited and badly supported Which is probably at least part of the reason that libc itself ends up being slower than a specific, targeted solution.
- mananaysiempre 5y agoUmm, what’s the story with Go on Linux? My understanding is that Linux explicitly supports making syscalls from your own code, it’s just that on platforms where the syscall story is a giant mess (32-bit x86) the prescription is to either use the slow historical interface (INT 80h) or to jump to the vDSO (which will do SYSENTER or SYSCALL or whatever—SYSENTER in particular has the lovely property of not saving the return address, so a common stub is pretty much architecturally required[1]). If I’m guessing correctly about what you’re referring to, the Go people did something in between, got broken in a Linux kernel release, complained at the kernel people, the kernel got a patch to unbreak them. The story on MacOS or OpenBSD, where the kernel developers will cheerfully tell you to take a hike if you make a syscall yourself, seems much worse to me. (And yes, I’d say there is a meaningful difference between a couple of instructions in the vDSO and Glibc’s endless wrappers.) [1]: https://lore.kernel.org/lkml/Pine.LNX.4.44.0212172225410.1368-100000@home.transmeta.com/ https://lore.kernel.org/lkml/Pine.LNX.4.44.0212172225410.136... ETA: Wait, no, I was thinking about the Android breakage[2]. What’s the Go story then? [2]: https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git/commit/?id=30bfa7b3488bfb1bb75c9f50a5fcac1832970c60 https://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git/...
- aw1621107 5y agoThis gets rather over my head, but my best guess is this bug having to do with the Go runtime underestimating how much stack space vDSO code may need (blog post at [0], fix at [1]). [0]: https://marcan.st/2017/12/debugging-an-evil-go-runtime-bug/ https://marcan.st/2017/12/debugging-an-evil-go-runtime-bug/ [1]: https://github.com/golang/go/commit/a158382b1c9c0b95a7d41865a405736be6bc585f https://github.com/golang/go/commit/a158382b1c9c0b95a7d41865...
- mananaysiempre 5y ago> I built 32 kernels, one for each bit of the SHA-1 prefix, which only took 29 minutes. Oh, that is evil, thank you. I even encountered a link to this article a couple of months ago[1], but wasn’t hooked enough to go and read it. Though the conclusion sounds somewhat dubious to me: the kernel doesn’t document or control stack usage limits for the vDSO, they happen to blow way up on a system built with obscure (if arguably well-motivated) compiler options, a language runtime that tries to minimize stack usage crashes as a result, and somehow the fault is with the runtime in question for not going via libc (which happens to virtually always run with a large stack and a guard page, thus turning this insidious concurrent memory corruption bug into a mere extremely unlikely crash)? More like we’re collectively garbage at accounting for our stack usage. To be fair to the kernel developers, I would also never guess, looking at this implementation of clock_gettime() [2], that you could compile it in such a way that it ends up requiring 4K of stack space on pain of memory corruption in concurrent programs only (it originating in the kernel source tree has little to do with the bug, it’s just weirdly-compiled userspace C code executing on a small unguarded stack). [1] in <https://utcc.utoronto.ca/~cks/space/blog/unix/UnixAPIAndCRuntime https://utcc.utoronto.ca/~cks/space/blog/unix/UnixAPIAndCRun...> via <https://utcc.utoronto.ca/~cks/space/blog/programming/CStackSizeInvisible https://utcc.utoronto.ca/~cks/space/blog/programming/CStackS...>, <https://utcc.utoronto.ca/~cks/space/blog/unix/StackSizeLimitWhen https://utcc.utoronto.ca/~cks/space/blog/unix/StackSizeLimit...>, and <https://utcc.utoronto.ca/~cks/space/blog/tech/StackSizeLimitWhy https://utcc.utoronto.ca/~cks/space/blog/tech/StackSizeLimit...>. [2] https://elixir.bootlin.com/linux/latest/C/ident/__cvdso_clock_gettime https://elixir.bootlin.com/linux/latest/C/ident/__cvdso_cloc...
- scottlamb 5y agojosefx> Also making system calls from your own code varies between prohibited and badly supported on most OSes. Some see calls that didn't pass through the system libc as a security issue and will intercept them, while Linux may just silently corrupt your process memory if you try something fancy as the Go team had to find out. On Linux, making syscalls directly is fine. Good point about other platforms, but many people only care about Linux, for better or worse. And the author's last paragraph (quoted below) suggests using an alternate/static-linking-friendly libc, not making direct syscalls yourself. Presumably on platforms where those alternate libcs aren't available, you continue using the standard libc. ryanhileman> If you're running into process startup time issues in a real world scenario and ever actually need to do this, it might be worth your time to profile and try one of the alternative libc implementations (like musl libc or diet libc). IMHO, the Go vDSO problem [1] wasn't due to making direct syscalls but basically calling a userspace library without meeting its assumptions. I'd describe Linux's vDSO as a userspace library for making certain syscalls with less overhead. (If you don't care about the overhead, you can call them as you'd call any other syscall instead.) It assumed the standard ABI, in which there's a guard page as well as typically a generous amount of stack to begin with. Golang called into it from a thread that used Go's non-standard ABI with less stack space available (Go's own functions check the stack size on entry and copy the stack if necessary) and no guard page. On some Linux builds (with -fstack-check, apparently used by Gentoo Hardened ), it actually used enough stack to overflow. Without a guard page, that caused memory corruption. [1] https://github.com/golang/go/issues/20427 https://github.com/golang/go/issues/20427
- stabbles 5y agoWhat's kinda neat about musl libc is that the interpreter/runtime linker and libc.so are the same executable, so that if you just dynamically link to libc, it does not need to open ld.so cache or locate and load libc.so.
- 2ton_jeff 5y agoA couple of years ago I did a "Terminal Video Series" segment that also highlights the runtime overhead of 12 other languages, C of course actually one of the best ones: https://2ton.com.au/videos/tvs_part1/ https://2ton.com.au/videos/tvs_part1/
- tialaramex 5y agoI was actually surprised for C how expensive that is, I'd expected maybe a dozen or so syscalls to set up the environment the provided runtime wants, but that's a lot of syscalls for not very much value. Both C++ and Rust are more expensive but they're setting up lots of stuff I might use in real programs, even if it's wasted for printing "hello" - but what on Earth can C need all those calls for when the C runtime environment is so impoverished anyway? Go was surprising to me in the opposite direction, they're setting up a pretty nice hosted environment, and they're not using many instructions or system calls to do that compared to languages that would say they're much more focused on performance. I'd have expected to find it closer to Perl or something, and it's really much lighter.
- aidenn0 5y agoglibc isn't particularly optimized for startup-time. It also defaults to dynamic linkage which adds several syscalls, and even if it is statically linked, it may dynamically load NSS plugins. (musl gets around the latter by hardcoding support for NSCD, a service that can cache the NSS results). C11 adds several things that benefit from early initialization (like everything around threads), but GCC had some level of support for most of them before that.
- dang 5y agoDiscussed at the time: C Runtime Overhead - https://news.ycombinator.com/item?id=8958867 https://news.ycombinator.com/item?id=8958867 - Jan 2015 (31 comments)
- ginko 5y agoI never quite understood why assembly wasn't part of programming language shootout competitions. C was always treated as the speed of light for computing, which didn't quite make sense to me.
- pjscott 5y agoIn my experience there's usually not much speed advantage to be had from assembly unless you have a specific thesis about how you're going to do better than the code that a good compiler would generate; e.g. the article author skipping C runtime setup overhead, or Mike Pall dissecting the ARM implementation of one of the bytecodes in LuaJIT (recommended!): https://www.reddit.com/r/programming/comments/hkzg8/author_of_luajit_explains_why_compilers_cant_beat/ https://www.reddit.com/r/programming/comments/hkzg8/author_o... Unless you can think of something you can do in assembly that a compiler just wouldn't be able to think of, their ability to generate good machine code is really quite impressive: https://ridiculousfish.com/blog/posts/will-it-optimize.html https://ridiculousfish.com/blog/posts/will-it-optimize.html
- jart 5y agoNormally it's better to focus on high-level time-complexity improving optimizations but there's still a whole lot of things where you really need assembly micro-optimizations, since they usually offer a 10x or 100x speedup. It's just that those things usually only concern core libraries. Stuff like crc32. But the rest of the time we're just writing code that glues all the assembly optimized subroutines together.
- matu3ba 5y agoThe link to gmane does not work, since the content is only available via NNTP: http://news.gmane.io/ http://news.gmane.io/ Do you have any backup etc?
- pjscott 5y agoI managed to track this down: http://lua-users.org/lists/lua-l/2011-02/msg00742.html http://lua-users.org/lists/lua-l/2011-02/msg00742.html
- cozzyd 5y agoSo, on my system (Fedora 34, glibc 2.33, gcc11, Ryzen 5 3600) a trivial program takes only about 1 ms according to time: $ cat trivial.c #include <stdio.h> int main(int nargs, char ** args) { FILE * f = fopen("/dev/null","w"); for (int i = 0; i < nargs; i++) { fprintf(f,"%s\n",args[i]); } return 0; } $ make trivial # just default CFLAGS $ time ./trivial real 0m0.001s user 0m0.000s sys 0m0.001s But if I add strace -tt, it does indeed take 9 ms, even if I redirect strace output $ time strace -tt ./trivial 2> /dev/null real 0m0.009s user 0m0.005s sys 0m0.004s So, is author just measuring strace overhead?
- justicezyx 5y agoBut the 1ms number is also measured with strace. Plus, the article is in 2015, and the author did not mention the CPU and other configuration. So that also make things muddy.
- cozzyd 5y agoYes, but if there are almost no syscalls, then strace is doing a lot less. Profiling my trivial program with callgrind shows (unsurprisingly) that the majority of the time is in dynamic library relocation and whatever __GI__tunables_init does: https://i.imgur.com/Yligh7S.png https://i.imgur.com/Yligh7S.png
- matu3ba 5y agostrace can have a significant overhead: https://www.brendangregg.com/blog/2014-05-11/strace-wow-much-syscall.html https://www.brendangregg.com/blog/2014-05-11/strace-wow-much... What does the output of `perf trace` say?
- cozzyd 5y ago$ perf trace -S ./trivial ? ( ): trivial/84044 ... [continued]: execve()) = 0 0.038 ( 0.002 ms): trivial/84044 brk() = 0xe02000 0.048 ( 0.001 ms): trivial/84044 arch_prctl(option: 0x3001, arg2: 0x7ffe4bdf0d60) = -1 EINVAL (Invalid argument) 0.067 ( 0.007 ms): trivial/84044 access(filename: 0xee77b500, mode: R) = -1 ENOENT (No such file or directory) 0.080 ( 0.006 ms): trivial/84044 openat(dfd: CWD, filename: 0xee777ee0, flags: RDONLY|CLOEXEC) = 3 0.087 ( 0.003 ms): trivial/84044 newfstatat(dfd: 3, filename: 0xee7776f5, statbuf: 0x7ffe4bdeff90, flag: 4096) = 0 0.092 ( 0.004 ms): trivial/84044 mmap(len: 271188, prot: READ, flags: PRIVATE, fd: 3) = 0x7fc2ee70d000 0.097 ( 0.001 ms): trivial/84044 close(fd: 3) = 0 0.118 ( 0.006 ms): trivial/84044 openat(dfd: CWD, filename: 0xee783e50, flags: RDONLY|CLOEXEC) = 3 0.126 ( 0.003 ms): trivial/84044 read(fd: 3, buf: 0x7ffe4bdf00e8, count: 832) = 832 0.130 ( 0.002 ms): trivial/84044 pread64(fd: 3, buf: 0x7ffe4bdefcf0, count: 784, pos: 64) = 784 0.134 ( 0.002 ms): trivial/84044 pread64(fd: 3, buf: 0x7ffe4bdefcb0, count: 48, pos: 848) = 48 0.137 ( 0.002 ms): trivial/84044 pread64(fd: 3, buf: 0x7ffe4bdefc60, count: 68, pos: 896) = 68 0.140 ( 0.002 ms): trivial/84044 newfstatat(dfd: 3, filename: 0xee7776f5, statbuf: 0x7ffe4bdeff90, flag: 4096) = 0 0.144 ( 0.003 ms): trivial/84044 mmap(len: 8192, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS) = 0x7fc2ee70b000 0.151 ( 0.013 ms): trivial/84044 pread64(fd: 3, buf: 0x7ffe4bdefbe0, count: 784, pos: 64) = 784 0.166 ( 0.006 ms): trivial/84044 mmap(len: 1892824, prot: READ, flags: PRIVATE|DENYWRITE, fd: 3) = 0x7fc2ee53c000 0.173 ( 0.010 ms): trivial/84044 mprotect(start: 0x7fc2ee562000, len: 1679360) = 0 0.185 ( 0.009 ms): trivial/84044 mmap(addr: 0x7fc2ee562000, len: 1363968, prot: READ|EXEC, flags: PRIVATE|FIXED|DENYWRITE, fd: 3, off: 0x26000) = 0x7fc2ee562000 0.196 ( 0.005 ms): trivial/84044 mmap(addr: 0x7fc2ee6af000, len: 311296, prot: READ, flags: PRIVATE|FIXED|DENYWRITE, fd: 3, off: 0x173000) = 0x7fc2ee6af000 0.202 ( 0.006 ms): trivial/84044 mmap(addr: 0x7fc2ee6fc000, len: 24576, prot: READ|WRITE, flags: PRIVATE|FIXED|DENYWRITE, fd: 3, off: 0x1bf000) = 0x7fc2ee6fc000 0.214 ( 0.004 ms): trivial/84044 mmap(addr: 0x7fc2ee702000, len: 33240, prot: READ|WRITE, flags: PRIVATE|FIXED|ANONYMOUS) = 0x7fc2ee702000 0.229 ( 0.001 ms): trivial/84044 close(fd: 3) = 0 0.242 ( 0.003 ms): trivial/84044 mmap(len: 8192, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS) = 0x7fc2ee53a000 0.248 ( 0.002 ms): trivial/84044 arch_prctl(option: SET_FS, arg2: 0x7fc2ee70c580) = 0 0.304 ( 0.005 ms): trivial/84044 mprotect(start: 0x7fc2ee6fc000, len: 12288, prot: READ) = 0 0.312 ( 0.004 ms): trivial/84044 mprotect(start: 0x403000, len: 4096, prot: READ) = 0 0.320 ( 0.006 ms): trivial/84044 mprotect(start: 0x7fc2ee780000, len: 8192, prot: READ) = 0 0.337 ( 0.011 ms): trivial/84044 munmap(addr: 0x7fc2ee70d000, len: 271188) = 0 0.365 ( 0.001 ms): trivial/84044 brk() = 0xe02000 0.368 ( 0.002 ms): trivial/84044 brk(brk: 0xe23000) = 0xe23000 0.377 ( 0.010 ms): trivial/84044 openat(dfd: CWD, filename: 0x402012, flags: CREAT|TRUNC|WRONLY, mode: IRUGO|IWUGO) = 3 0.398 ( 0.002 ms): trivial/84044 newfstatat(dfd: 3, filename: 0xee6c995a, statbuf: 0x7ffe4bdf0650, flag: 4096) = 0 0.401 ( 0.002 ms): trivial/84044 ioctl(fd: 3, cmd: TCGETS, arg: 0x7ffe4bdf05b0) = -1 ENOTTY (Inappropriate ioctl for device) 0.408 ( 0.002 ms): trivial/84044 write(fd: 3, buf: 0xe02480, count: 10) = 10 0.413 ( ): trivial/84044 exit_group() = ? Summary of events: trivial (84044), 70 events, 92.1% syscall calls errors total min avg max stddev (msec) (msec) (msec) (msec) (%) --------------- -------- ------ -------- --------- --------- --------- ------ mmap 8 0 0.041 0.003 0.005 0.009 14.32% mprotect 4 0 0.025 0.004 0.006 0.010 21.35% openat 3 0 0.022 0.006 0.007 0.010 19.30% pread64 4 0 0.018 0.002 0.004 0.013 62.41% munmap 1 0 0.011 0.011 0.011 0.011 0.00% newfstatat 3 0 0.008 0.002 0.003 0.003 17.21% access 1 1 0.007 0.007 0.007 0.007 0.00% brk 3 0 0.006 0.001 0.002 0.002 13.93% arch_prctl 2 1 0.003 0.001 0.001 0.002 1.69% close 2 0 0.003 0.001 0.001 0.001 0.00% read 1 0 0.003 0.003 0.003 0.003 0.00% write 1 0 0.002 0.002 0.002 0.002 0.00% ioctl 1 1 0.002 0.002 0.002 0.002 0.00% execve 1 0 0.000 0.000 0.000 0.000 0.00% So, looks like total syscall overhead is on the order of 0.1 ms? Granted, it's a significant part of the runtime, but I think all the relocations and such are driving the libc overhead (as shown in callgrind output: https://i.imgur.com/Yligh7S.png https://i.imgur.com/Yligh7S.png ) And great, now I know a new way to use perf! (I initially tried profiling with perf but it doesn't get enough samples to be useful!).
- SavantIdiot 5y agoAnyone have the link to the scoring architecture OP references? The provided link 404s.