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.

Advertisements

~ by stormwyrm on 2013-04-30.

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

 
%d bloggers like this: