Hello, Running top command with idlestat tool doesn't show any frequency information sometimes. I have run the program with the following command - #sudo idlestat --trace -t 5 -f /tmp/myoutput /usr/bin/top and it ended up with the following output where there is no frequency state information. The file "myoutput" doesn't have any cpu_frequency entry either. Total trace buffer: 153896 kB Log is 4.999488 secs long with 675 events clusterA@state hits total(us) avg(us) min(us) max(us) C6-SNB 163 4955450.00 30401.53 0.00 141946.00 cpu0@state hits total(us) avg(us) min(us) max(us) C1-SNB 1 912.00 912.00 912.00 912.00 C6-SNB 115 4996270.00 43445.83 67.00 211819.00 cpu0 wakeups name count irq040 eth0 50 cpu1@state hits total(us) avg(us) min(us) max(us) C1-SNB 3 10809.00 3603.00 27.00 10742.00 C6-SNB 62 4985746.00 80415.26 59.00 223952.00 cpu1 wakeups name count irq018 ata_piix 6 cpu2@state hits total(us) avg(us) min(us) max(us) C1-SNB 3 10800.00 3600.00 26.00 10745.00 C6-SNB 52 4986684.00 95897.77 5724.00 223957.00 cpu2 wakeups name count cpu3@state hits total(us) avg(us) min(us) max(us) C1-SNB 20 15123.00 756.15 121.00 10895.00 C6-SNB 47 4962591.00 105587.04 1.00 223950.00 cpu3 wakeups name count Does that mean processors spent all time in idle state and none in active state?
Hi Salman,
On Thu, Jun 19, 2014 at 1:36 PM, Salman Ahmed salmanyam@yahoo.com wrote:
Hello, Running top command with idlestat tool doesn't show any frequency information sometimes. I have run the program with the following command - # sudo idlestat --trace -t 5 -f /tmp/myoutput /usr/bin/top and it ended up with the following output where there is no frequency state information. The file "myoutput" doesn't have any cpu_frequency entry either.
There was a bug in the waitpid logic, a fix for which was committed to the git tree.
Please try this again with the new code.
Also, you might want to use it as such:
sudo idlestat --trace -t 5 -f /tmp/myoutput -- /usr/bin/top
(note the --) to ensure that idlestat doesn't get confused about the command being another commandline parameter.
Total trace buffer: 153896 kB Log is 4.999488 secs long with 675 events clusterA@state hits total(us) avg(us) min(us) max(us) C6-SNB 163 4955450.00 30401.53 0.00 141946.00 cpu0@state hits total(us) avg(us) min(us) max(us) C1-SNB 1 912.00 912.00 912.00 912.00 C6-SNB 115 4996270.00 43445.83 67.00 211819.00 cpu0 wakeups name count irq040 eth0 50 cpu1@state hits total(us) avg(us) min(us) max(us) C1-SNB 3 10809.00 3603.00 27.00 10742.00 C6-SNB 62 4985746.00 80415.26 59.00 223952.00 cpu1 wakeups name count irq018 ata_piix 6 cpu2@state hits total(us) avg(us) min(us) max(us) C1-SNB 3 10800.00 3600.00 26.00 10745.00 C6-SNB 52 4986684.00 95897.77 5724.00 223957.00 cpu2 wakeups name count cpu3@state hits total(us) avg(us) min(us) max(us) C1-SNB 20 15123.00 756.15 121.00 10895.00 C6-SNB 47 4962591.00 105587.04 1.00 223950.00 cpu3 wakeups name count Does that mean processors spent all time in idle state and none in active state?
-- Best Regards Salman Ahmed
linaro-dev mailing list linaro-dev@lists.linaro.org http://lists.linaro.org/mailman/listinfo/linaro-dev
Hello Amit,
I have pulled changes and run with your suggested following command sudo ./idlestat --trace -t 5 -f /tmp/myoutput -- top
But still it came up with the output without any frequency information.
Total trace buffer: 153896 kB Log is 4.999537 secs long with 702 events clusterA@state hits total(us) avg(us) min(us) max(us) C6-SNB 175 4964449.00 28368.28 0.00 183908.00 cpu0@state hits total(us) avg(us) min(us) max(us) C6-SNB 105 4995794.00 47578.99 49.00 223927.00 cpu0 wakeups name count irq040 eth0 39 cpu1@state hits total(us) avg(us) min(us) max(us) C1-SNB 5 852.00 170.40 41.00 446.00 C6-SNB 64 4996275.00 78066.80 113.00 323886.00 cpu1 wakeups name count irq018 ata_piix 14 cpu2@state hits total(us) avg(us) min(us) max(us) C1-SNB 35 9158.00 261.66 121.00 1396.00 C6-SNB 51 4969643.00 97443.98 51.00 323897.00 cpu2 wakeups name count cpu3@state hits total(us) avg(us) min(us) max(us) C1-SNB 4 383.00 95.75 26.00 129.00 C6-SNB 49 4997267.00 101985.04 67.00 319905.00 cpu3 wakeups name count
The problem probably is not in idlestat tool. There is no cpu_frequency line in the trace file.
-- Best Regards Salman Ahmed
On Thursday, 19 June 2014, 18:23, Amit Kucheria amit.kucheria@linaro.org wrote: Hi Salman,
On Thu, Jun 19, 2014 at 1:36 PM, Salman Ahmed salmanyam@yahoo.com wrote:
Hello, Running top command with idlestat tool doesn't show any frequency information sometimes. I have run the program with the following command - # sudo idlestat --trace -t 5 -f /tmp/myoutput /usr/bin/top and it ended up with the following output where there is no frequency state information. The file "myoutput" doesn't have any cpu_frequency entry either.
There was a bug in the waitpid logic, a fix for which was committed to the git tree.
Please try this again with the new code.
Also, you might want to use it as such:
sudo idlestat --trace -t 5 -f /tmp/myoutput -- /usr/bin/top
(note the --) to ensure that idlestat doesn't get confused about the command being another commandline parameter.
Total trace buffer: 153896 kB Log is 4.999488 secs long with 675 events clusterA@state hits total(us) avg(us) min(us) max(us) C6-SNB 163 4955450.00 30401.53 0.00 141946.00 cpu0@state hits total(us) avg(us) min(us) max(us) C1-SNB 1 912.00 912.00 912.00 912.00 C6-SNB 115 4996270.00 43445.83 67.00 211819.00 cpu0 wakeups name count irq040 eth0 50 cpu1@state hits total(us) avg(us) min(us) max(us) C1-SNB 3 10809.00 3603.00 27.00 10742.00 C6-SNB 62 4985746.00 80415.26 59.00 223952.00 cpu1 wakeups name count irq018 ata_piix 6 cpu2@state hits total(us) avg(us) min(us) max(us) C1-SNB 3 10800.00 3600.00 26.00 10745.00 C6-SNB 52 4986684.00 95897.77 5724.00 223957.00 cpu2 wakeups name count cpu3@state hits total(us) avg(us) min(us) max(us) C1-SNB 20 15123.00 756.15 121.00 10895.00 C6-SNB 47 4962591.00 105587.04 1.00 223950.00 cpu3 wakeups name count Does that mean processors spent all time in idle state and none in active state?
-- Best Regards Salman Ahmed
linaro-dev mailing list linaro-dev@lists.linaro.org http://lists.linaro.org/mailman/listinfo/linaro-dev
On Fri, Jun 20, 2014 at 9:47 AM, Salman Ahmed salmanyam@yahoo.com wrote:
Hello Amit,
I have pulled changes and run with your suggested following command sudo ./idlestat --trace -t 5 -f /tmp/myoutput -- top
But still it came up with the output without any frequency information.
What platform are you running this on? Is cpufreq enabled? What is the output of 'cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_frequencies' ?
Total trace buffer: 153896 kB Log is 4.999537 secs long with 702 events clusterA@state hits total(us) avg(us) min(us) max(us) C6-SNB 175 4964449.00 28368.28 0.00 183908.00 cpu0@state hits total(us) avg(us) min(us) max(us) C6-SNB 105 4995794.00 47578.99 49.00 223927.00 cpu0 wakeups name count irq040 eth0 39 cpu1@state hits total(us) avg(us) min(us) max(us) C1-SNB 5 852.00 170.40 41.00 446.00 C6-SNB 64 4996275.00 78066.80 113.00 323886.00 cpu1 wakeups name count irq018 ata_piix 14 cpu2@state hits total(us) avg(us) min(us) max(us) C1-SNB 35 9158.00 261.66 121.00 1396.00 C6-SNB 51 4969643.00 97443.98 51.00 323897.00 cpu2 wakeups name count cpu3@state hits total(us) avg(us) min(us) max(us) C1-SNB 4 383.00 95.75 26.00 129.00 C6-SNB 49 4997267.00 101985.04 67.00 319905.00 cpu3 wakeups name count
The problem probably is not in idlestat tool. There is no cpu_frequency line in the trace file.
-- Best Regards Salman Ahmed
I am running it on Intel x86 platform and the output of 'cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_frequencies' is 3101000 3100000 2800000 2600000 2400000 2200000 2000000 1800000 1600000
--Thanks, Salman
On Friday, 20 June 2014, 10:26, Amit Kucheria amit.kucheria@linaro.org wrote: On Fri, Jun 20, 2014 at 9:47 AM, Salman Ahmed salmanyam@yahoo.com wrote:
Hello Amit,
I have pulled changes and run with your suggested following command sudo ./idlestat --trace -t 5 -f /tmp/myoutput -- top
But still it came up with the output without any frequency information.
What platform are you running this on? Is cpufreq enabled? What is the output of 'cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_frequencies'
?
Total trace buffer: 153896 kB Log is 4.999537 secs long with 702 events clusterA@state hits total(us) avg(us) min(us) max(us) C6-SNB 175 4964449.00 28368.28 0.00 183908.00 cpu0@state hits total(us) avg(us) min(us) max(us) C6-SNB 105 4995794.00 47578.99 49.00 223927.00 cpu0 wakeups name count irq040 eth0 39 cpu1@state hits total(us) avg(us) min(us) max(us) C1-SNB 5 852.00 170.40 41.00 446.00 C6-SNB 64 4996275.00 78066.80 113.00 323886.00 cpu1 wakeups name count irq018 ata_piix 14 cpu2@state hits total(us) avg(us) min(us) max(us) C1-SNB 35 9158.00 261.66 121.00 1396.00 C6-SNB 51 4969643.00 97443.98 51.00 323897.00 cpu2 wakeups name count cpu3@state hits total(us) avg(us) min(us) max(us) C1-SNB 4 383.00 95.75 26.00 129.00 C6-SNB 49 4997267.00 101985.04 67.00 319905.00 cpu3 wakeups name count
The problem probably is not in idlestat tool. There is no cpu_frequency line in the trace file.
-- Best Regards Salman Ahmed
Hello Amit,
Actually, I ran it on the same machine with the same command again and these time the output has frequency information-
$ sudo ./idlestat --trace -t 5 -f /tmp/myoutput -- top
Log is 4.999547 secs long with 710 events clusterA@state hits total(us) avg(us) min(us) max(us) C6-SNB 174 4953094.00 28466.06 0.00 183909.00 cpu0@state hits total(us) avg(us) min(us) max(us) C1-SNB 1 630.00 630.00 630.00 630.00 C6-SNB 111 4995205.00 45001.85 8.00 279064.00 cpu0 wakeups name count irq040 eth0 50 cpu1@state hits total(us) avg(us) min(us) max(us) C6-SNB 54 4997809.00 92552.02 125.00 323888.00 cpu1 wakeups name count irq018 ata_piix 10 cpu2@state hits total(us) avg(us) min(us) max(us) C1-SNB 35 19993.00 571.23 121.00 11699.00 C6-SNB 48 4957068.00 103272.25 51.00 323891.00 3101 8 487.00 60.88 1.00 291.00 1600 78 14303.00 183.37 1.00 6144.00 cpu2 wakeups name count cpu3@state hits total(us) avg(us) min(us) max(us) C1-SNB 4 379.00 94.75 25.00 128.00 C6-SNB 59 4997441.00 84702.39 60.00 323878.00 cpu3 wakeups name count
So, output sometimes contains frequency information and sometimes it doesn't with the same command. When it does not, trace file does not contain any cpu_frequency entry. So, the problem may not be with idlestat tool since it just parses trace file. Is it possible there is any bug in kernel tracing code?
--
Best Regards Salman Ahmed
On Friday, 20 June 2014, 11:26, Salman Ahmed salmanyam@yahoo.com wrote: I am running it on Intel x86 platform and the output of 'cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_frequencies' is 3101000 3100000 2800000 2600000 2400000 2200000 2000000 1800000 1600000
--Thanks, Salman
On Friday, 20 June 2014, 10:26, Amit Kucheria amit.kucheria@linaro.org wrote: On Fri, Jun 20, 2014 at 9:47 AM, Salman Ahmed salmanyam@yahoo.com wrote:
Hello Amit,
I have pulled changes and run with your suggested following command sudo ./idlestat --trace -t 5 -f /tmp/myoutput -- top
But still it came up with the output without any frequency information.
What platform are you running this on? Is cpufreq enabled? What is the output of 'cat /sys/devices/system/cpu/cpu0/cpufreq/scaling_available_frequencies'
?
Total trace buffer: 153896 kB Log is 4.999537 secs long with 702 events clusterA@state hits total(us) avg(us) min(us) max(us) C6-SNB 175 4964449.00 28368.28 0.00 183908.00 cpu0@state hits total(us) avg(us) min(us) max(us) C6-SNB 105 4995794.00 47578.99 49.00 223927.00 cpu0 wakeups name count irq040 eth0 39 cpu1@state hits total(us) avg(us) min(us) max(us) C1-SNB 5 852.00 170.40 41.00 446.00 C6-SNB 64 4996275.00 78066.80 113.00 323886.00 cpu1 wakeups name count irq018 ata_piix 14 cpu2@state hits total(us) avg(us) min(us) max(us) C1-SNB 35 9158.00 261.66 121.00 1396.00 C6-SNB 51 4969643.00 97443.98 51.00 323897.00 cpu2 wakeups name count cpu3@state hits total(us) avg(us) min(us) max(us) C1-SNB 4 383.00 95.75 26.00 129.00 C6-SNB 49 4997267.00 101985.04 67.00 319905.00 cpu3 wakeups name count
The problem probably is not in idlestat tool. There is no cpu_frequency line in the trace file.
-- Best Regards Salman Ahmed
On Fri, Jun 20, 2014 at 4:01 PM, Salman Ahmed salmanyam@yahoo.com wrote:
Hello Amit,
Actually, I ran it on the same machine with the same command again and these time the output has frequency information-
$ sudo ./idlestat --trace -t 5 -f /tmp/myoutput -- top
Log is 4.999547 secs long with 710 events clusterA@state hits total(us) avg(us) min(us) max(us) C6-SNB 174 4953094.00 28466.06 0.00 183909.00 cpu0@state hits total(us) avg(us) min(us) max(us) C1-SNB 1 630.00 630.00 630.00 630.00 C6-SNB 111 4995205.00 45001.85 8.00 279064.00 cpu0 wakeups name count irq040 eth0 50 cpu1@state hits total(us) avg(us) min(us) max(us) C6-SNB 54 4997809.00 92552.02 125.00 323888.00 cpu1 wakeups name count irq018 ata_piix 10 cpu2@state hits total(us) avg(us) min(us) max(us) C1-SNB 35 19993.00 571.23 121.00 11699.00 C6-SNB 48 4957068.00 103272.25 51.00 323891.00 3101 8 487.00 60.88 1.00 291.00 1600 78 14303.00 183.37 1.00 6144.00 cpu2 wakeups name count cpu3@state hits total(us) avg(us) min(us) max(us) C1-SNB 4 379.00 94.75 25.00 128.00 C6-SNB 59 4997441.00 84702.39 60.00 323878.00 cpu3 wakeups name count
So, output sometimes contains frequency information and sometimes it doesn't with the same command. When it does not, trace file does not contain any cpu_frequency entry. So, the problem may not be with idlestat tool since it just parses trace file. Is it possible there is any bug in kernel tracing code?
Does this happen when you run for longer than 5 seconds? Try running it for 15 seconds 10 times. I wonder if your platform isn't transitioning P-states in 5 seconds.
I tried 10 times running 15 seconds and out of that 3 times I got output without any P-state information.
Can you try changing your workload?
On Fri, Jun 20, 2014 at 4:57 PM, Salman Ahmed salmanyam@yahoo.com wrote:
I tried 10 times running 15 seconds and out of that 3 times I got output without any P-state information.
-- Thanks, Salman Ahmed
On Friday, 20 June 2014, 16:49, Amit Kucheria amit.kucheria@linaro.org wrote: On Fri, Jun 20, 2014 at 4:01 PM, Salman Ahmed salmanyam@yahoo.com wrote:
Hello Amit,
Actually, I ran it on the same machine with the same command again and these time the output has frequency information-
$ sudo ./idlestat --trace -t 5 -f /tmp/myoutput -- top
Log is 4.999547 secs long with 710 events clusterA@state hits total(us) avg(us) min(us) max(us) C6-SNB 174 4953094.00 28466.06 0.00 183909.00 cpu0@state hits total(us) avg(us) min(us) max(us) C1-SNB 1 630.00 630.00 630.00 630.00 C6-SNB 111 4995205.00 45001.85 8.00 279064.00 cpu0 wakeups name count irq040 eth0 50 cpu1@state hits total(us) avg(us) min(us) max(us) C6-SNB 54 4997809.00 92552.02 125.00 323888.00 cpu1 wakeups name count irq018 ata_piix 10 cpu2@state hits total(us) avg(us) min(us) max(us) C1-SNB 35 19993.00 571.23 121.00 11699.00 C6-SNB 48 4957068.00 103272.25 51.00 323891.00 3101 8 487.00 60.88 1.00 291.00 1600 78 14303.00 183.37 1.00 6144.00 cpu2 wakeups name count cpu3@state hits total(us) avg(us) min(us) max(us) C1-SNB 4 379.00 94.75 25.00 128.00 C6-SNB 59 4997441.00 84702.39 60.00 323878.00 cpu3 wakeups name count
So, output sometimes contains frequency information and sometimes it doesn't with the same command. When it does not, trace file does not contain any cpu_frequency entry. So, the problem may not be with idlestat tool since it just parses trace file. Is it possible there is any bug in kernel tracing code?
Does this happen when you run for longer than 5 seconds? Try running it for 15 seconds 10 times. I wonder if your platform isn't transitioning P-states in 5 seconds.
-
Amit Kucheria -
Salman Ahmed