Fix race condition in spawning tracer process

[devonestes]

We were somewhat reliably missing the first garbage collection event because when we spawned our tracer, we were setting the tracing flag in the function to be executed in our tracer. This means the runner and tracer were running concurrently for a moment, and the runner hit a GC threshold before the tracer was able to set the appropriate tracing flag!

Now we explicitly block the runner from running the function to be run until the tracing flag is set.

With this patch applied I now see all the GC events that we should see.

Also, I have absolutely no idea how to test this other than the tests we already had in place.

Resolves #234 and #205 🎉

[devonestes]

Also, I re-ran the benchmarks in #205 on this branch and this is what I see now:

$ mix run samples/wtf.exs
Operating System: macOS"
CPU Information: Intel(R) Core(TM) i5-4260U CPU @ 1.40GHz
Number of Available Cores: 4
Available memory: 8 GB
Elixir 1.7.1
Erlang 21.0

Benchmark suite executing with the following configuration:
warmup: 0 ns
time: 10 μs
memory time: 1 s
parallel: 1
inputs: none specified
Estimated total run time: 12.00 s

Benchmarking ++ array concat...
Warning: The function you are trying to benchmark is super fast, making measurements more unreliable!
This holds especially true for memory measurements.
See: https://github.com/PragTob/benchee/wiki/Benchee-Warnings#fast-execution-warning

You may disable this warning by passing print: [fast_warning: false] as configuration options.

Benchmarking Enum.map(10 list)...
Benchmarking Enum.map(10)...
Benchmarking Enum.map(2)...
Benchmarking Enum.map(50)...
Benchmarking Enum.map(empty)...
Benchmarking Integer addition...
Benchmarking String concatention...
Benchmarking adding a head to an array...
Warning: The function you are trying to benchmark is super fast, making measurements more unreliable!
This holds especially true for memory measurements.
See: https://github.com/PragTob/benchee/wiki/Benchee-Warnings#fast-execution-warning

You may disable this warning by passing print: [fast_warning: false] as configuration options.

Benchmarking just return 10 list...
Benchmarking noop...
Warning: The function you are trying to benchmark is super fast, making measurements more unreliable!
This holds especially true for memory measurements.
See: https://github.com/PragTob/benchee/wiki/Benchee-Warnings#fast-execution-warning

You may disable this warning by passing print: [fast_warning: false] as configuration options.

Benchmarking noop nil...
Warning: The function you are trying to benchmark is super fast, making measurements more unreliable!
This holds especially true for memory measurements.
See: https://github.com/PragTob/benchee/wiki/Benchee-Warnings#fast-execution-warning

You may disable this warning by passing print: [fast_warning: false] as configuration options.

Name                                ips        average  deviation         median         99th %
adding a head to an array          10 M         100 ns     ±0.00%         100 ns         100 ns
noop                               10 M         100 ns     ±0.00%         100 ns         100 ns
noop nil                           10 M         100 ns     ±0.00%         100 ns         100 ns
++ array concat                     5 M         200 ns     ±0.00%         200 ns         200 ns
Enum.map(empty)                     2 M         500 ns   ±141.42%         500 ns        1000 ns
Integer addition                    2 M         500 ns   ±141.42%         500 ns        1000 ns
String concatention                 2 M         500 ns   ±141.42%         500 ns        1000 ns
just return 10 list                 2 M         500 ns   ±141.42%         500 ns        1000 ns
Enum.map(2)                         1 M        1000 ns     ±0.00%        1000 ns        1000 ns
Enum.map(10)                     0.33 M        3000 ns     ±0.00%        3000 ns        3000 ns
Enum.map(10 list)                0.25 M        4000 ns    ±70.71%        4000 ns        6000 ns
Enum.map(50)                   0.0588 M       17000 ns     ±0.00%       17000 ns       17000 ns

Comparison:
adding a head to an array          10 M
noop                               10 M - 1.00x slower
noop nil                           10 M - 1.00x slower
++ array concat                     5 M - 2.00x slower
Enum.map(empty)                     2 M - 5.00x slower
Integer addition                    2 M - 5.00x slower
String concatention                 2 M - 5.00x slower
just return 10 list                 2 M - 5.00x slower
Enum.map(2)                         1 M - 10.00x slower
Enum.map(10)                     0.33 M - 30.00x slower
Enum.map(10 list)                0.25 M - 40.00x slower
Enum.map(50)                   0.0588 M - 170.00x slower

Memory usage statistics:

Name                         Memory usage
adding a head to an array            72 B
noop                                 72 B - 1.00x memory usage
noop nil                             72 B - 1.00x memory usage
++ array concat                      72 B - 1.00x memory usage
Enum.map(empty)                     120 B - 1.67x memory usage
Integer addition                     72 B - 1.00x memory usage
String concatention                  72 B - 1.00x memory usage
just return 10 list                 240 B - 3.33x memory usage
Enum.map(2)                         240 B - 3.33x memory usage
Enum.map(10)                        496 B - 6.89x memory usage
Enum.map(10 list)                   448 B - 6.22x memory usage
Enum.map(50)                       1760 B - 24.44x memory usage

**All measurements for memory usage were the same**

Looks much more realistic 😉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉 🎉

[michalmuskala]

Awesome work, @devonestes! The results look very realistic now.

[PragTob]

Who's the best? @devonestes that's who! :tada:

---

Your run time measurements have me slightly worried though. Seems like the macosx nanosecond measurements seem to be only in increments of 100. Furthermore the noop nil isn't coming out at 0ns as I'd expect it to :thinking: But that's for another day to ponder.

[devonestes]

My runtimes are funky in those benchmarks because I had the measurement time set for 0.00001 seconds for runtime measurement. Not the best sample size. If I bump it up to something reasonable I get much more accurate results.