3

I used ftrace to trace two events, cpu_frequency and cpu_idle. I am not able to find out any documentation which states how to interpret this information. I have provided two snippets from the generated trace file below, and I need to understand how to interpret cpu_frequency & cpu_idle traced events information. I have wrote my confusion below, please answer the question and provide your own insights.

FOR CPU_Frequency:
1. What is the format of the timestamp?
2. Why there are two events for each new operating frequency point, does each of the event means that the CPU started operating at that frequency or are these entry/exit pairs?

Trace output:

# tracer: nop
#
# entries-in-buffer/entries-written: 36062/36062   #P:1  
#  
#                              _-----=> irqs-off
#                             / _----=> need-resched
#                            | / _---=> hardirq/softirq
#                            || / _--=> preempt-depth
#                            ||| /     delay
#           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
#              | |       |   ||||       |         |
kworker/0:1H-27    [000] ...1  1130.362603: cpu_frequency: state=1190400 cpu_id=0
kworker/0:1H-27    [000] ...1  1130.362609: cpu_frequency: state=1190400 cpu_id=0
kworker/0:1H-27    [000] ...1  1130.411934: cpu_frequency: state=300000 cpu_id=0
kworker/0:1H-27    [000] ...1  1130.411947: cpu_frequency: state=300000 cpu_id=0
kworker/0:1H-27    [000] ...1  1131.532595: cpu_frequency: state=1190400 cpu_id=0
kworker/0:1H-27    [000] ...1  1131.532599: cpu_frequency: state=1190400 cpu_id=0
kworker/0:1H-27    [000] ...1  1131.581758: cpu_frequency: state=300000 cpu_id=0
kworker/0:1H-27    [000] ...1  1131.581768: cpu_frequency: state=300000 cpu_id=0

FOR CPU_Idle:
1. What does the state=4294967295 means here, what cpu_idle state is it?
2. Where can I get the documentation/information about what these states actually mean?

 <idle>-0     [000] d..2  1960.307101: cpu_idle: state=3 cpu_id=0
 <idle>-0     [000] ...2  1960.310722: cpu_idle: state=4294967295 cpu_id=0
 <idle>-0     [000] d..2  1960.310741: cpu_idle: state=3 cpu_id=0
 <idle>-0     [000] ...2  1960.312114: cpu_idle: state=4294967295 cpu_id=0
 <idle>-0     [000] d..2  1960.312131: cpu_idle: state=3 cpu_id=0
 <idle>-0     [000] .N.2  1960.314410: cpu_idle: state=4294967295 cpu_id=0
 <idle>-0     [000] d..2  1960.314980: cpu_idle: state=3 cpu_id=0
 <idle>-0     [000] .N.2  1960.316077: cpu_idle: state=4294967295 cpu_id=0
 <idle>-0     [000] d..2  1960.316539: cpu_idle: state=3 cpu_id=0

thanks.

0

For CPU_Frequency:

  1. The timestamp format is "secs.usecs". You can find more about this on ftrace documentation: https://www.kernel.org/doc/Documentation/trace/ftrace.txt
  2. I think it shows the transition delay between frequencies.

For CPU_Idle:

  1. '4294967295' means an exit from the current state.
  2. The documentation can be found here: https://www.kernel.org/doc/Documentation/trace/events-power.txt

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.