Page 1 of 2
Question about server profiling
Posted: Thu Mar 23, 2017 1:15 pm
by selsner
I am interested in the total time for one server "loop" from profiling. For us it is something like 700ms maximum with ~300 "clients". Is this too much? I am trying to find if our server is too slow or the network might be bad on our side....
Re: Question about server profiling
Posted: Mon Mar 27, 2017 1:16 pm
by timurhai
It looks like too big, i think, even for 300 clients.
There are 3 measures: Prep, Proc and Post where are most of yours 700ms?
Prep - reading message.
Proc - process message.
Post - writing an answer message.
Re: Question about server profiling
Posted: Mon Mar 27, 2017 1:35 pm
by selsner
Ok, this is a copy paste of a current output of the server.
Code: Select all
Served connections per second: 90
Mon 27 Mar 15:33.14: Server load profiling:
Clients per second: 87.10, Now: 1
Prep: 0.05, Proc: 318.50, Post: 0.00, Tolal: 318.54 ms
So it takes a long time to process messages. Is there a way to fiurther profile the proc step?
Re: Question about server profiling
Posted: Mon Mar 27, 2017 2:20 pm
by timurhai
Wow, i thought that "Prep" (network reading should take the most time).
For now there is no simple way to profile Proc step.
How much CPU load? How much running / total jobs on afserver?
Re: Question about server profiling
Posted: Mon Mar 27, 2017 2:24 pm
by selsner
load average is 0.56, the host (8 core 16Gb) is pretty bored. There are 600 jobs in the queue, 17 rendering, 20 ready.
Re: Question about server profiling
Posted: Mon Mar 27, 2017 3:58 pm
by timurhai
Strange.
I think that your afserver load should not be so much.
Try to measure after some major changes, for example, most jobs deleted, no jobs running and much more queued/running.
Re: Question about server profiling
Posted: Tue Mar 28, 2017 4:52 pm
by selsner
Could it be there is a bug in the profiler? From the code profiler.cpp Line 108:
Code: Select all
double prep = 0.0;
double proc = 0.0;
double post = 0.0;
for( int i = 0; i < ms_profiles.size(); i++)
{
prep += toFloat( ms_profiles[i]->m_tstart ) - toFloat( ms_profiles[i]->m_tinit );
proc += toFloat( ms_profiles[i]->m_tfinish ) - toFloat( ms_profiles[i]->m_tstart );
proc += toFloat( ms_profiles[i]->m_tcollect ) - toFloat( ms_profiles[i]->m_tfinish );
}
prep /= double( ms_stat_period ) / 1000.0;
proc /= double( ms_stat_period ) / 1000.0;
post /= double( ms_stat_period ) / 1000.0;
In the for loop, should the last line be:
Code: Select all
post += toFloat( ms_profiles[i]->m_tcollect ) - toFloat( ms_profiles[i]->m_tfinish );
instead of
Code: Select all
proc += toFloat( ms_profiles[i]->m_tcollect ) - toFloat( ms_profiles[i]->m_tfinish );
post instead of
proc ??
Re: Question about server profiling
Posted: Tue Mar 28, 2017 5:29 pm
by selsner
I changed it and get about 10ms for proc now (which was constantly 0 before). I also noticed that there were 2 other afserver instances running (for whatever reason) maybe they are making the high times....
Re: Question about server profiling
Posted: Tue Mar 28, 2017 6:18 pm
by timurhai
Hi.
Yes, it is a bug in the code!
Can you commit it, please?
Re: Question about server profiling
Posted: Wed Mar 29, 2017 6:00 pm
by seven11
While you are fixing the bug, Can you fix the spelling mistake?
Prep: 0.15, Proc: 0.01, Post: 8.50, Tolal: 8.67 ms.
Tolal > Total
Thx
Scott