On 4/17/07, Daniel Stenberg <daniel_at_haxx.se> wrote:
>
> I had a first look at these just now and three things struck me:
>
> 1 - gettimeofday() certainly is called a lot and indeed takes a significant
> time. We should address this (somehow).

It is called in cycles in many cases.
A pattern to solve it something like this :

gettimeofday ();
int cycle_counter = 0;

for (i....) {

   DO_THE_JOB

   if (! (++cycle_counter % TIME_RECALCULATION_CYCLES_NUM)) {
        gettimeofday ();
}

An example from curl-loader here, look for get_tick_count (),
that calls gettimeofday ():
http://curl-loader.svn.sourceforge.net/viewvc/curl-loader/trunk/curl-loader/loader_smooth.c?view=markup

Better, that somebody with a deep understanding of curl will do the job.

>
> 2 - dprintf_formatf() seems to take quite a lot of time as well and I find
> it strange. What kind of *printf() operations are made with your tests?
> How come this function is used so much?

This is the question, that I was going to ask you. :)
Y can dig inside into the callstasks for .prof files and look, where
it is called.
What I see is, e.g.:
-----------------------------------------------
                0.00 0.00 1/239402 curl_msnprintf [67]
                0.04 0.00 37300/239402 curl_mvaprintf [27]
                0.08 0.01 79201/239402 curl_maprintf [21]
                0.12 0.02 122900/239402 curl_mvsnprintf [16]
[12] 19.9 0.24 0.03 239402 dprintf_formatf [12]
                0.02 0.00 5696319/5696319 addbyter [34]
                0.01 0.00 7782971/7782971 alloc_addbyter [45]

Just a hypotheses below:
We are using (as posted) options:
CURLOPT_VERBOSE with 1
CURLOPT_DEBUGFUNCTION with client_tracing_function

All these CURL_INFO, etc messages are somehow printed to
the buffers delivered. May be there is something there, that may be improved?

More details:
The profiling was done in a non-verbose mode. Still
client_tracing_function receives
all messages, but prints to a logfile only errors (CURL_ERROR). There was no any
errors during profiling.
Y can see here the patch, that we use to filter errors and to enable
for a user to segregate among really important errors and just infos:
http://curl-loader.svn.sourceforge.net/viewvc/curl-loader/trunk/curl-loader/patches/curl-trace-info-error.patch?view=markup

For our client_tracing_function you can look here:
http://curl-loader.svn.sourceforge.net/viewvc/curl-loader/trunk/curl-loader/loader.c?view=markup

> 3 - I figure we need more precision on the 5th and 6th columns (how long
> each specific time takes by itself) to better identify functions that
> seem to take too long.

Y can get more understanding from the lower (call-stack) sections
of *.prof outputs

For event more detailed information, please, find code-type gprof
output for the same expetiments with more details attached.

-- 
Sincerely,
Robert Iakobashvili,
coroberti %x40 gmail %x2e com
...................................................................
Navigare necesse est, vivere non est necesse
...................................................................
http://curl-loader.sourceforge.net
An open-source HTTP/S, FTP/S traffic
generating, and web testing tool.