Skip to content

On-CPU and Off-CPU time mismatch #748

@pidtuner

Description

@pidtuner

First of all, thank you for this amazing tool. I tried to find an existing issue matching this but could not find it.

Describe the bug

I have a C++ application that waits most of the time in a std::condition_variable, and every 15 seconds performs a short task:

std::mutex mMutex;
std::condition_variable mCV;
// ...
std::unique_lock<std::mutex> lockGuard(mMutex);
mCV.wait_for(lockGuard, std::chrono::milliseconds(15000), endCondition);
// ...
// some short task

I created a 10.5 seconds perf record as explained in the README:

perf record \
    -e cycles \                             # on-CPU profiling
    -e sched:sched_switch --switch-events \ # off-CPU profiling
    --sample-cpu \                          # track on which core code is executed
    -m 8M \                                 # reduce chance of event loss
    --aio -z \                              # reduce disk-I/O overhead and data size
    --call-graph dwarf \                    # we definitely want backtraces
    <your application>

Then loaded in latest continuous pre-release (although the same shows in earlier versions):

Image

As it can be observed, the Time Line the cycles show where the "short task" activity happens, but the "on/off CPU time" ratio (76.3% / 23.7%) seems incorrect, as most of the time is spend waiting in the mCV.wait_for call.

Furthermore, in the Top Down pane, the off CPU column for the std::condition_variable::wait_for<?> symbol call shows 0%. I would expect this call to have the highest off-CPU percentage.

Is this a bug or am I interpreting the presented data incorrectly? Thank you for your help!

Version Info (please complete the following information):

Image

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions