Hacker News Reader

Comment by jart | Hacker News Reader

Why does hello world take 1.8ms to run? That's ~5,000,000 cycles. By my measurements with Actually Portable Executable the latency of vfork+execve+exit+wait4 on a physical computer running Linux should be 25µs. That's two orders of a magnitude difference. https://github.com/jart/cosmopolitan/blob/master/test/libc/s...

View on HN

How would you time this? I tried a simple C hello world and got a similar ~2ms run time. But I was just running "time ./hello" at a Bash prompt, which a) only has 1ms resolution and b) probably measures some shell overhead. Running it under "strace -tt" so I could see where the slow bits were made it 10x slower :-(

Edit: FWIW, building with "gcc foo.c -o foo -O2 -s -Wall --static" was slightly faster than without the --static. And "musl-gcc foo.c -o foo -O2 -s -Wall --static" was slightly better again. Maybe 0.5ms improvement in total. I'm on Ubuntu 20 x64, gcc 9, Intel Xeon W-2133.

You could write a non-shell launcher using fork+exec+wait and present the results with finer granularity than time(1). There may be something adequate available off-the-shelf but I’m not familiar with it.

Got you covered. https://github.com/jart/cosmopolitan/blob/master/examples/ru...

    $ git clone https://github.com/jart/cosmopolitan && cd cosmopolitan
    $ make -j8 o//examples/rusage.com o//examples/hello.com
    $ o//examples/rusage.com o//examples/hello.com
    hello world 123
    RL: took 90µs wall time
    RL: ballooned to 108kb in size
    RL: needed 106µs cpu (0% kernel)
    RL: caused 13 page faults (100% memcpy)

This one has a tiny bit more overhead than the practical minimum you saw earlier in the benchmark. Note that APE binaries start off as shell scripts so the first run is going to be slower. It's something I'm working towards improving in a variety of ways. Here's the executive summary of the upcoming changes:

    int ws, pid;
    CHECK_NE(-1, (pid = fork()));
    if (!pid) {
      execve("ape.com", (char *const[]){"ape.com", 0}, environ);
      perror("execve");
      _Exit(127);
    }
    CHECK_EQ(pid, wait(&ws));
    CHECK_TRUE(WIFEXITED(ws));
    CHECK_EQ(0, WEXITSTATUS(ws));

Here's the latency of the various execution strategies:

    FORK+EXEC+EXIT+WAIT      │       APE │ APE-LOADER │ BINFMT_MISC
    ───────────────────────────────────────────────────────────────
    fork() + execve()        │      55µs │       66µs │        56µs
    vfork() + execve()       │      25µs │      446µs │        35µs
    /bin/sh -c ./ape (1st)   │     485µs │      457µs │       170µs
    /bin/sh -c ./ape (avg)   │     148µs │      466µs │       159µs

OK, I did "for i in {1..10}; do o//examples/rusage.com o//examples/hello.com; done" and the lowest wall time I got was 1,140us, which is a lot more than your 90us for some reason. There's probably something wrong with my setup. Maybe it takes my machine that long to come out of some P-state or C-state sleep mode I don't understand.

Then for my musl-gcc hello world, I did, "for i in {1..10}; do o//examples/rusage.com ../hello" and the lowest wall time I got was 120us. But most of the runs were closer to 350us.

So, my attempt to answer your, "Why does hello world take 1.8ms to run?" question is: a) they timed it with "time" which measures lots of overhead, b) there's something wrong with their setup that means they are mostly timing the time taken for a CPU core to wake up.

See https://gist.github.com/jart/0bb0d1ff6836c3936f8153c24ddef5b... for an extremely tiny Linux binary and the rusage.com program which provides a better single-shot measurement of execution time.

By default I think rust links libc and produces a dynamically linked executable. If you run strace I bet you'll find it's doing a ton of syscalls related to searching for and loading dynamic assets.

Rust produces primarily static executables, with the exception of libc usually being dynamically loaded.

That's what he said isn't it?

> and produces a dynamically linked executable

It does. You can't have a static executable that dynamically links with glibc.

OK? As I said, it produces static executables that dynamically link with libc. I would not call that a dynamic executable, especially when already specifying that libc is loaded dynamically. I don't think most people would classify "loads libc dynamically" as a "dynamic executable".

Gentlemen there's no need to argue because you're both right. Yes, Rust linkage is predominantly static. However in order to link libc dynamically on System V, it officially speaking needs to be a dynamic object rather than an executable, in most cases. I just checked on my system with a Rust binary to confirm. The Elf64_Ehdr::e_type is set to ET_DYN rather than ET_EXEC.

I think they would. You can get a fully static binary if you link with musl. That's common with Rust.

How did you convert time to the cycles ? Cycles are more about instruction set.

Sure, put a "roughly" in there. It's a simple multiplication by clock speed. This is Justine who designed APE. I think they know.

Edit, and also no, cycles are not "more about instruction set". They're pulses of electricity that make their way through a chip, they are about as far from instruction-set-specific as it gets.

I've rounded the number and added a tilde since you're right. There's actually a lot of interesting depth behind this subject for x86 alone. RDTSC timestamps are guaranteed to be invariant across all models irrespective of clock speed (except k8) so a mapping exists between RDTSC reported clock cycles and nanoseconds; however, it usually isn't accessible on client grade hardware and has to be measured haphazardly by the operating system. In my experience on CPUs the last ten years it's usually in the ballpark of .323018 for both Intel and AMD. Multiply ticks by that and you get a pretty good nanosecond approximation. If you want a fixed point expression for your benchmarks:

    static inline unsigned long ClocksToNanos(unsigned long x, unsigned long y) {
      // approximation of round(x*.323018) which is usually
      // the ratio between inva rdtsc ticks and nanoseconds
      unsigned long difference = y >= x ? y - x : ~x + y + 1;
      return (difference * 338709) >> 20;
    }

That's just one quick and dirty way your approximation could be approximated. Should work great for any benchmark games. Obviously don't use it for like, an X-ray or something. You can get the RDTSC value as follows:

    static inline unsigned long Rdtsc(void) {
      unsigned long Rax, Rdx;
      asm volatile("rdtsc" : "=a"(Rax), "=d"(Rdx) : /* no inputs */ : "memory");
      return Rdx << 32 | Rax;
    }

Intel also has recommendations for things like using CPUID and memory fences if you need to reign in speculative execution, but they can be costly. If you want to go even deeper then RDTSCP has a nice feature that lets you know if the operating system switched you to a different core during your measurement interval because it gives you TSC_AUX.

I'm not sure whether any of that timing precision will do any good on GitHub Actions, where this seems to be running. I don't think the machine is going to be quiet enough to get a good measurement of anything.

Noise and jitter in the VM should cancel out with repeated measurements.

Here's something interesting. If I run my test in a RHEL5 (Linux c. 2010) VirtualBox VM then it actually goes faster than a modern Linux kernel running on bare metal, taking only 14µs. If I run it in a RHEL7 VM then it needs 131µs.

So >1ms hello world execution should be a red flag. If that's actually the latency of GitHub's kernels and can't be explained by something like a shell script doing the time interval measurements, then it'd be interesting to learn what it's doing.

It appears helloworld is the only test with any repeats, and it only has 5 repeats. https://github.com/hanabi1224/Programming-Language-Benchmark... (Also, you can't average out the VM scheduling something else during the test, if it is constantly scheduling other stuff as it is a very busy build machine.)

Here's the measurement code, it appears to be significantly more complicated than a simple fork/exec/wait loop but that could just be all the C# getting in the way: https://github.com/hanabi1224/Programming-Language-Benchmark... Note that we are definitely measuring the C# async runtime to some degree. Nevertheless you are probably right that the bulk of this 1.8ms is in the executable under test, and it truly is just bloat. Running `hyperfine ./empty-main-function` from rustc on my Mac gives 0.8ms.

Looks like it might be async C# thread sleep code launching bash launching the benchmark.

Is that due to SPECTRE & Meltdown mitigations?

I disable Spectre mitigations on my Linux workstation since it doesn't host VMs or browsers. I'm sure if those were enabled it'd go much slower. But either way it's pretty clear that a lot of stuff got added to the kernel since 2.6.18 that slows down process launches dramatically, then some of it probably got optimized, and the rest stuck. Would be interesting to know what it is.

You should be able to disable them for your VM guests, but I don’t know if VirtualBox does.

I'm guessing from a bit of googling that APE stands for the Actually Portable Executable[0] (which once I found I realised I had read about before, but I wasn't aware of the acronym).

[0] https://justine.lol/ape.html

It was mentioned in the top level comment.

Dumb question: why are cycles and instruction set not related?

Because instruction set is the interface and the architecture is the implementation? Or something else?

Very simple: CPUs do not execute a constant number of instructions on each cycle. Some instructions are really slow, and their slowness is measured in cycles. You can usually do one XOR in one cycle, because it's a really simple piece of circuitry. Some instructions have complicated circuitry, which means that it takes multiple pulses of electricity to move the input signals through all the logic gates inside. XOR can do it in one pulse, but a division might take 20 pulses. Cycles are just pulses.

One important component of a program's performance, especially in numeric code, is how many instructions it manages to execute per cycle. If you have written your program's instructions in a 'good' order, then the CPU will e.g. not queue up many divisions in a row that depend on each other. It can do two different things at the same time. You can't do anything in less than one cycle, but you can do two of the same thing in the same cycle if you have two available execution units for that task.

The most direct answer to your question is that different instruction sets have different ideas about how much work a single instruction should do. The basic divide is between CISC (complex instructions, x86 qualifies) and RISC (basic instructions, ARM). It is a dramatic oversimplification but one instruction in a CISC architecture might involve 10 instructions in a RISC. So you can't compare instruction counts between architectures. But you can compare cycles and still make a bit of sense.

If this is interesting to you, you should try this game, where you can build a CPU purely out of the most basic logic gates: https://nandgame.com/

A cache miss stalling the CPU can be worth 100 CPU cycles or more.

So, instructions can have different pulses. therefore, different cycles. How did we end up 1.8ms to 5M cycles ?

2.6 Ghz * 1.8ms = 4,680,000 CPU cycles. To reiterate, this is independent of instructions. That's the number of CPU cycles it took to execute hello world.

thank you.

Cycles are a function of time and clock rate. Most CPUs run at 1-4 GHz, so multiplying seconds by a billion gives you a cycle estimate within a factor of 10.

Because Rust is not competing with the HQ9 language. It's for writing programs that do more than just Hello World, so the startup initializes common things for non-toy programs.

the file you linked to is doing file I/O. that's much more than fork/exec. Hopefully on the benchmark system it's tmpfs but it still has to go through VFS layer.

The IO is setup and isn’t inside the benchmarked region.

Possibly initialization?

Reply on news.ycombinator.com