mperham/dalli — pull request #315 by joerixaop (2013-01-11 12:11:49+00:00)
Title: Improve performance for multi get 

I tried converting a program from the memcached gem to dalli, and encounterd an issue with the performance of dalli.

The following numbers are all for the same data set. 4603 items are fetched from memcached, the combined size of the values is about 7MB. (This is not actually something we would load in our application in one request, but it was easy to test with).

For the memcached gem the multi get is split in blocks of 100 items (because it uses the text protocol, where there is a limit on the length of the keys field).
Initially I kept this code for the dalli conversion, then I tried to change to 1 multi get call in the hopes that this would improve performance. It did the opposite.
Apparently splice! is really inefficient when used repeatedly on the same string and even more so when there are many appends to that string.
Replacing splice! with splice (and keeping track of the position) was much faster, but still much slower than the memcached gem.

* **Memcached (47*100)**
0.70 0.79 0.81 0.90
* **Patched dalli (47*100)**
1.7 1.7 1.7 1.7 1.8 1.9 2.1 2.2 2.2 2.3 2.3
* **Patched dalli (24*200)**
1.7 1.7 1.8 2.0 2.0 2.1 2.1 2.2 2.2
* **Patched dalli (10*500)**
1.8 1.9 1.9 1.9 2.0 2.1
* **Unpatched dalli (47*100)**
17.6 18.1 18.2 18.3 18.4 19.3
* **Unpatched dalli (24*200)**
25.0 25.2 25.4 26.3
* **Unpatched dalli (10*500)**
83.8 91.8 92.8

Profile unpatched (top 5 lines, 47*100, in larger batches splice! dominates even more)

% cumulative self self total
time seconds seconds calls ms/call ms/call name
55.78 23.74 23.74 36832 0.64 0.64 String#slice!
12.17 28.92 5.18 9304 0.56 0.56 IO#write
5.78 31.38 2.46 96 25.63 300.31 Dalli::Server#multi_response_nonblock
2.04 32.25 0.87 13809 0.06 0.08 Hash#hash
1.81 33.02 0.77 27912 0.03 1.35 MonitorMixin.mon_synchronize

Profile patched (top 5 lines, 47*100, the profile looks similar for 10*500)

% cumulative self self total
time seconds seconds calls ms/call ms/call name
19.94 5.25 5.25 9304 0.56 0.56 IO#write
6.84 7.05 1.80 96 18.75 74.79 Dalli::Server#multi_response_nonblock
6.23 8.69 1.64 27912 0.06 0.65 MonitorMixin.mon_synchronize
4.71 9.93 1.24 1291 0.96 0.97 IO#read_nonblock
3.99 10.98 1.05 18416 0.06 0.07 Dalli::Client#servers_in_use