Tuesday, March 9, 2010

Some more Lusca Profiling..

More Lusca profiling of a simple test workload:

samples % image name symbol name
234266 6.7052 libc-2.3.6.so _int_malloc
138031 3.9507 libc-2.3.6.so vfprintf
111831 3.2008 libc-2.3.6.so calloc
104393 2.9879 libc-2.3.6.so malloc_consolidate
98984 2.8331 libc-2.3.6.so memcpy
91783 2.6270 libc-2.3.6.so _int_free
72578 2.0773 libc-2.3.6.so memset
69068 1.9769 libc-2.3.6.so free
50473 1.4446 squid clientTryParseRequest
50064 1.4329 squid memPoolAlloc
45211 1.2940 libc-2.3.6.so re_search_internal
40469 1.1583 squid httpRequestFree
39227 1.1228 squid statHistBin
38916 1.1139 squid comm_select
36974 1.0583 libc-2.3.6.so _IO_default_xsputn
36260 1.0378 squid memPoolFree

.. CPU is still taken up in the standard areas: memory allocation, stdio, and memcpy.

memcpy() I can't tackle right now. malloc() and friends I can tackle, but it may cause strange bugs and I'm not willing to commit anything which upsets stability too much right now. But vfprintf() is fun.

51285 22.7881 libc-2.3.6.so vsprintf
168714 74.9667 libc-2.3.6.so vsnprintf
156434 100.000 libc-2.3.6.so vfprintf

.. so most of the CPU is vsnprintf().

2549 1.0775 squid httpHeaderPutStrf
78253 33.0790 squid memBufVPrintf
153322 64.8121 libc-2.3.6.so snprintf
13601 100.000 libc-2.3.6.so vsnprintf

.. memBufVPrintf():

33231 36.8652 httpHeaderPutStrf
55577 61.6549 packerPrintf
7225 100.000 memBufVPrintf

.. snprintf():

5021 2.8271 squid clientAccessCheckDone
31897 17.9597 squid clientSendHeaders
53339 30.0327 squid xitoa
85548 48.1681 squid urlCanonical
7870 100.000 libc-2.3.6.so snprintf

.. so it's likely that eliminating the random calls through the printf() code to do "stuff" like assembling the URL and request/reply strings will shave off about 4% of this workload. But the biggest issue right now is the stupidly large amount of CPU being used in the memory allocation routines.

But the annoying one is memcpy():

10557 7.3665 squid httpAccept
20779 14.4992 squid stringDup
37010 25.8250 squid httpHeaderEntryPackInto
47882 33.4113 squid connStateFree
143177 100.000 libc-2.3.6.so memcpy

.. there's no memcpy() call in connStateFree. Which means I need to go hunting to figure out what's going on. Grr.

No comments:

Post a Comment