Profiling Arcueid
After compiling Arcueid with profiling information, and running news.arc with ApacheBench to generate 100 requests, the results seem to be rather interesting, although not quite unexpected:
Flat profile:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls s/call s/call name
28.50 11.29 11.29 287 0.04 0.09 gc
11.37 15.80 4.51 197333024 0.00 0.00 TYPE
3.91 17.35 1.55 3340957 0.00 0.00 __arc_vector_marker
3.89 18.89 1.54 35946478 0.00 0.00 arc_hash_update
3.57 20.30 1.42 190118632 0.00 0.00 mark
3.36 21.63 1.33 57789411 0.00 0.00 envval
2.85 22.76 1.13 88862762 0.00 0.00 nextcont
2.52 23.76 1.00 9775784 0.00 0.00 arc_hash_final
2.32 24.68 0.92 95741775 0.00 0.00 TYPE
2.09 25.51 0.83 142012842 0.00 0.00 VINDEX
1.92 26.27 0.76 89952347 0.00 0.00 contenv
1.77 26.97 0.70 188319700 0.00 0.00 TYPE
1.74 27.66 0.69 9540002 0.00 0.00 hash_lookup
1.72 28.34 0.68 287 0.00 0.00 free_unused_bibop
1.50 28.94 0.60 11201327 0.00 0.00 cons_marker
1.41 29.50 0.56 1130474 0.00 0.00 __arc_update_cont_envs
1.16 29.96 0.46 7119452 0.00 0.00 bibop_alloc
1.14 30.41 0.45 19305490 0.00 0.00 VINDEX
It seems that almost 30% of the system’s time is being spent in the garbage collector. I suppose the next step really is to make use of a more efficient GC algorithm, or to use what we have today less aggressively.
Arcueid 弧 