Re: The sample time decreases when I run high cpu utilization job.

On 03/10/2016 12:38 PM, Tim Chou wrote:
> Hi All,
> 
> I use oprofile to try profile the database server's (MySQL) performance.
> 
> I start with this command before I start my test:
> sudo nohup operf --pid `pgrep mysqld` &
> All the tests will be run for 150s.
> 
> When the CPU utilization is low, the sample number seems reasonable.
> However, when the CPU utilization is very high, more than 100%, the sample number decreases dramatically.
> 
> *Because the sample numbers change a lot in these tests. So I'm not sure if I can still believe the results I got in the high CPU utilization case. I think the sampling should be done in a fix time interval. So the sampling number should be similar.*
> 
> The total sample numbers are 42417612 samples and 1226 samples, for 70% CPU utilization and 100% CPU utilization.
> 
> *Is my understanding right? Or what's the right way to use oprofile in the high CPU utilization case?*
> 
> Looking forward to your reply.
> 
> Thanks,
> Tim

Hi Tim,

I suspect that the sampling is being throttled by perf in the kernel and that is reducing the number of samples.  Look through the /etc/log/messages to see if there are message related to that.

oprofile in this exmaple should be using the default event for example on my machine:

$ ophelp -d
CPU_CLK_UNHALTED:100000:0:1:1

So one sample every 100,000 clock cycles.  For a machine with 2.4GHz clock that would be 24,000 samples per processor.
You might try increasing the sampling interval listed by "ophelp -d" something like:

sudo nohup operf -e CPU_CLK_UNHALTED:1000000:0:1:1 -pid `pgrep mysqld`&

See if increasing the interval between samples improves the situation.

-Will

> ---------------------------------------------------------------------------------
> Below are the symbols results.
> 70% cpu utilization:
> samples  %        image name               symbol name
> 2340974   5.5390  mysqld                   MYSQLparse(THD*)
> 1024614   2.4243  mysqld                   rec_get_offsets_func(unsigned char const*, dict_index_t c
> onst*, unsigned long*, unsigned long, mem_block_info_t**)
> 610260    1.4439  mysqld                   lex_one_token(YYSTYPE*, THD*) [clone .constprop.119]
> 
>>100% cpu utilization:
> 
> samples  %        image name               symbol name
> 63        4.8951  libc-2.22.so <http://libc-2.22.so>             __strcmp_sse2_unaligned
> 60        4.6620  mysqld                   fill_schema_collation(THD*, TABLE_LIST*, Item*)
> 44        3.4188  mysqld                   my_strnncollsp_utf8
> 29        2.2533  libc-2.22.so <http://libc-2.22.so>             __memcpy_avx_unaligned
> 
> 
> 
> ------------------------------------------------------------------------------
> Transform Data into Opportunity.
> Accelerate data analysis in your applications with
> Intel Data Analytics Acceleration Library.
> Click to learn more.
> http://pubads.g.doubleclick.net/gampad/clk?id=278785111&iu=/4140
> 
> 
> 
> _______________________________________________
> oprofile-list mailing list
> [email protected]
> https://lists.sourceforge.net/lists/listinfo/oprofile-list
> 


------------------------------------------------------------------------------
Transform Data into Opportunity.
Accelerate data analysis in your applications with
Intel Data Analytics Acceleration Library.
Click to learn more.
http://pubads.g.doubleclick.net/gampad/clk?id=278785111&iu=/4140