Interpreting the results of perf record

TechUserQuest · 03-17-2017, 01:51 AM

Hi,

I am trying to get the performance data on a (x86_64) Linux machine using the "perf tool". The intent of this exercise is to find out the "hostspots" in my program when I trigger a specific set of operations that result in high CPU utilization.

The output of the top -H command when I trigger the operations is as follows -

top - 01:39:43 up 6:09, 1 user, load average: 0.33, 0.32, 0.35
Tasks: 101 total, 2 running, 99 sleeping, 0 stopped, 0 zombie
Cpu0 : 0.3%us, 0.3%sy, 0.0%ni, 99.0%id, 0.0%wa, 0.0%hi, 0.3%si, 0.0%st
Cpu1 : 96.0%us, 4.0%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 7375464k total, 3939016k used, 3436448k free, 13100k buffers
Swap: 0k total, 0k used, 0k free, 3623696k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
733 root 20 0 3682m 3.3g 3.2g R 99 47.3 148:38.14 T1

From the above output,

1. 96% time is spent in running user space processes on CPU 1

2. Thread "T1" is the thread that contributes to the bulk of the CPU utilization and %CPU of this thread is 99

Pls note that the time duration during which the thread T1 reports 99-100% CPU utilization is ~50 seconds

When I look at the perf data captured by executing the command “perf record -e cpu-clock --freq=8000 --call-graph -t 733 sleep 20” during the time thread "T1" reports 99% CPU utilization, this is what I see –

+ 3.99% T1 processTest.elf [.] fun_F1 `
+ 3.98% T1 processTest.elf [.] fun_F2
+ 2.33% T1 processTest.elf [.] fun_F3
+ 2.27% T1 processTest.elf [.] fun_F4
+ 1.67% T1 processTest.elf [.] fun_F5
+ 1.48% T1 processTest.elf [.] fun_F6
+ 1.47% T1 processTest.elf [.] fun_F7
+ 1.45% T1 processTest.elf [.] fun_F8
+ 1.37% T1 processTest.elf [.] fun_F9
+ 1.36% T1 processTest.elf [.] fun_F10

From the above capture, I am not able to find out what the hotspots in my program are.

The overhead of the top 10 functions in the "T1" thread adds up to ~21% and the sum of the overhead percentages of the entire sample set is ~50%. Since the thread "T1" is reporting ~100% CPU utilization (~96% of which is in the user space), I expect that the sum of overhead percentages of user space functions in the perf data to be closer to 96%, which is not the case as per the data captured.

Please let me know on -

1. How to interpret the above perf data and correlate it to the top command output in the above case.

2. Do I need to use some other perf event type other than cpu-clock to get more info on the program hotspots?

TIA,
TachUserQuest

MensaWater · 03-17-2017, 02:09 PM

Did the rapture occur in the OP's part of the world?

norobro · 03-17-2017, 02:29 PM

I'm "left behind" too.

rtmistler · 03-17-2017, 02:47 PM

Mention of religion in technical threads is not allowed. While I realize the comments were intended to be light hearted, please realize that all may not agree with this interpretation. Furthermore it is perhaps better within a thread to try to help a newly registered LQ member versus attempt to make jokes about their first post.

Hi TechUserQuest and welcome to LQ.

Please realize that the post you've made contains a title along and does not cover any details about your question. Please edit your question or reply to this thread to add more detail. If you have any questions about how to ask a more effective question, or how to use the LQ site, please see the links in the LQ Site FAQ.

Best Regards.

MensaWater · 03-20-2017, 01:10 PM

Quote:

Originally Posted by rtmistler

Mention of religion in technical threads is not allowed.

You mean other than in signatures? I see direct religious messages in the signature of more than one user here at LQ. Will you be enforcing this rule on them?

rtmistler · 03-20-2017, 01:21 PM

Quote:

Originally Posted by MensaWater

You mean other than in signatures? I see direct religious messages in the signature of more than one user here at LQ.

It is allowed in user signatures and not within technical threads.

This was discussed in a thread in the suggestions and feedback forum: here.

Quote:

Originally Posted by MensaWater

Will you be enforcing this rule on them?

Please report discussions or use of religion within technical threads using the report button.

And thank you to TechUserQuest for updating their question. Let's please return to their question now that it has much more detail, and contend with that. Regarding the off-topic stuff, please start a different thread, visit the other discussion I've cited, or send me PM.

@TechUserQuest,

Perhaps your thread is not yielding the CPU properly.

Is there a way you can post the code, or representative code for that thread T1?

Is it a program which you're using the source or have written the source for?

Or do you only have a binary?

rtmistler · 03-20-2017, 01:36 PM

A brute force thing which I've done for performance bottlenecks in my programming is to develop a timestamp macro which sends output to stdout or to a log file and I put the macro at various points in my code, example only, not compiled or tested, just ad hoc written in my reply here:

Code:

#define TIME_MARK(st) (printf("%s::%d.%d\n", st, seconds, milliseconds))

// the seconds and milliseconds I derived from one of the time calls, such as time(), whatever gives me the seconds and nanoseconds since the epoch, or just system start time, I just need something which gives me seconds and milliseconds

//some code
TIME_MARK("a");
function_call();
TIME_MARK("b");

// What that does is tells me about how long I was in my function, named function_call().  I place these around, using the alphabet, or numbers and zero in on what is taking so very long.  Sometimes you surprise yourself and then hit yourself up on the side of your head at your stupidity.  Or sometimes not.

That is a "for what it's worth" set of thoughts, which is to instrument time markers within your code to help you determine where in your code you take time, with the acceptance that by printing stuff out, you are "taking time". Therefore if you have to figure out milli or micro-seconds worth of precision (1) the general Linux kernel isn't going to help you much, and (2) this method will not work too well for you.

TechUserQuest · 03-21-2017, 12:04 AM

Quote:

Originally Posted by rtmistler

It is allowed in user signatures and not within technical threads.

This was discussed in a thread in the suggestions and feedback forum: here.

Please report discussions or use of religion within technical threads using the report button.

And thank you to TechUserQuest for updating their question. Let's please return to their question now that it has much more detail, and contend with that. Regarding the off-topic stuff, please start a different thread, visit the other discussion I've cited, or send me PM.

@TechUserQuest,

Perhaps your thread is not yielding the CPU properly.

Is there a way you can post the code, or representative code for that thread T1?

Is it a program which you're using the source or have written the source for?

Or do you only have a binary?

Thank you for the response @rtmistler. Thread T1 represents a program that I have the source for. Unfortunately, I cannot post the code. I will check if it is possible to post the representative code and get back.

Thanks,
TechUserQuest