Benchmark in section 10.1 returning strange values

[mguimas]

Hi,

the benchmark in elixir_in_action_code_samples/ch10/profile_cache is returning the following results

$ iex -S mix
Erlang/OTP 20 [erts-9.2] [source] [64-bit] [smp:4:4] [ds:4:4:10] [async-threads:10] [hipe] [kernel-poll:false] [dtrace]

Interactive Elixir (1.5.2) - press Ctrl+C to exit (type h() ENTER for help)
iex(1)> Profiler.run(PageCache, 100000)

304625 reqs/sec

:ok
iex(2)> Profiler.run(PageCache, 100000, 100)

528910 reqs/sec

:ok
iex(3)>

Here are some more data:

iex(9)> Profiler.run(PageCache, 100000, 2)

305392 reqs/sec

:ok
iex(10)> Profiler.run(PageCache, 100000, 4)

389874 reqs/sec

:ok
iex(11)> Profiler.run(PageCache, 100000, 8)

324331 reqs/sec

:ok
iex(12)> Profiler.run(PageCache, 100000, 16)

360170 reqs/sec

:ok
iex(14)> Profiler.run(PageCache, 100000, 32)

381613 reqs/sec

:ok
iex(15)> Profiler.run(PageCache, 100000, 64)

460793 reqs/sec

:ok
iex(16)> Profiler.run(PageCache, 100000, 128)

534101 reqs/sec

:ok
iex(17)> Profiler.run(PageCache, 100000, 256)

543486 reqs/sec

:ok
iex(18)>

These are strange as instead of decreasing as in the book, the throughput is increasing?!
What am I doing wrong here?

I am with a Macbook Pro, 2.6 GHz Intel Core i5, 16 GB 1600 MHz DDR3, macOS Sierra 10.12.6, Erlang 20.2 and Elixir 1.5.2.

I had to change the code of the example to use Map instead of HashDict and to depend on Elixir 1.5.2 in mix.exs.

Thanks

[sasa1977]

I just checked on my machine, and I get similar results as you.

Likely it happens because maps are more efficient than HashDict (since with HashDict, I still get the same degradation). That said, the point of the text still stands - the throughput increase is not as dramatical as we'd expect it to be. Once maps are replaced with ETS tables, you should see a larger increase as you add concurrency to the story.

I'm currently working on the update for Elixir in Action, so I'll revise these numbers.

[mguimas]

Beware: the book in its current edition refers to a decrease in throughput as concurrency raises ...

"The third parameter to Profiler.run specifies the concurrency level. Here, you’re starting 100 processes, each one issuing 100,000 requests to the single page-cache process. Somewhat surprisingly, the measured throughput is significantly smaller." (page 249)

but, on the contrary to the book, the above results show that the measured throughput is raising, and it is not clear why ...

[sasa1977]

Yes, I understand that. As I mentioned, the throughput is still decreasing with HashDict. I'll probably need to make the example a bit more involved to reach the throughput decrease with maps. The thing is that we cache only one item, and maps are now much more efficient than HashDict (which wasn't the case when the book has been published). If we cached more items, and things were being constantly added to and deleted from the cache, the throughput would ultimately degrade, even with maps. ETS tables would have much more stable behaviour in such cases.

Also, even in this simple case, you can notice that the throughput is not increasing as you'd expect it to. In your tests, you do get some increase, but certainly not 2x which one would expect to reach on a two-core machine. In contrast, with ETS-based cache you will notice a more significant increase as you start adding cores.

[scout119]

@sasa1977 What OS did you use for the book? I am seeing really bad results on Windows 10 Pro (i7-5820K 3.30GHz, 6 cores)

Non ETS:

iex(33)> Profiler.run(PageCache, 100_000)

266_672 reqs/sec

iex(34)> Profiler.run(PageCache, 100_000, 100)

1_257 reqs/sec

ETS:

iex(30)> Profiler.run(EtsPageCache, 100_000)

3_225_806 reqs/sec

iex(31)> Profiler.run(EtsPageCache, 100_000, 100)

81_039 reqs/sec

[sasa1977]

My main OS is macos.

I've just tried it out on Windows 10 (quad core), the 2nd-edition branch, and here's what I've got:

non ETS:

mix run -e "Bench.run(KeyValue)" 
245682 operations/sec

mix run -e "Bench.run(KeyValue, concurrency: 100)" 
317935 operations/sec

ETS:

mix run -e "Bench.run(EtsKeyValue)" 
1828488 operations/sec

mix run -e "Bench.run(EtsKeyValue, concurrency: 100)" 
3575259 operations/sec

[scout119]

Sorry, it was my mistake. Reporting was not taking into account the number of concurrent clients.