New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 739574 link

Starred by 3 users

Issue metadata

Status: Archived
Owner:
Closed: Jul 2017
Cc:
EstimatedDays: ----
NextAction: ----
OS: Chrome
Pri: 1
Type: Bug



Sign in to add a comment

cpu_data_collector.cc: ERROR: Bad format at all_time_in_state. Dropping sample.

Project Member Reported by alemate@chromium.org, Jul 6 2017

Issue description

On behalf of another googler:

In /var/log/ui/ui.LATEST, we are seeing a lot of lines which look like these:

[4643:5045:0705/160236.779356:ERROR:cpu_data_collector.cc(387)] Bad format at "126000		196869		196869" in /sys/devices/system/cpu/cpufreq/all_time_in_state. Dropping sample.

In fact, if I look over all the files in /var/log/ui/ui.*
I find that about 25% of all log lines are this line.

Is this to be expected? We have seen this for quite a while now, but did not address it since it was relatively low priority. Also, from a quick search, it seems like this CL might be related.

 
We probably do not need this error message at all.
Adding UMA metric should be more effective.
Adding link to relevant CL for convenience: https://codereview.chromium.org/2853863002/
I think it is because cpu number is 4, but only 3 has freq data, so the entire row is dropped. I am not sure whether I should add the case to consider this situation as correct.
It is also worth noting that some of the CPUs are turned off on our device, so not all 4 cores are used.
Ah, I see, it would be great to know how all_time_in_state file is generated. But currently I could only presume the format based on existing several known situations including reporting 'N/A' in #29 of  crbug.com/548510 .
This is what the file looks like on our machine:

localhost ~ # cat /sys/devices/system/cpu/cpufreq/all_time_in_state 
freq		cpu0		cpu1		cpu2		cpu3		
126000		1501		1501		
216000		327		327		
408000		86		86		
600000		143		143		
696000		49		49		
816000		38		38		
1008000		90		90		
1200000		697		697		
1416000		1538		1538
Thanks for providing the file, could you share the method to turn off cpu? I need to test it locally.

Cc: amstan@chromium.org
I'm not sure exactly how we turned off the CPUs. This happened a long time ago, but amstan@ who was working with us at the time, should be able to tell us more. Earlier today, he said that the kernel's DTS file may be relevant: https://cs.corp.google.com/chromeos_public/src/third_party/kernel/v3.14/arch/arm/boot/dts/rk3288-rialto-rev0.dts
Please see:

src/private-overlays/overlay-variant-veyron-rialto-private/scripts/build_kernel_image.sh

TLDR: maxcpus=2 in the kernel cmdline
Thanks for the explanation, I am wondering what happens if cpu1 is off, does the all_time_in_state look like this?
freq		cpu0		cpu1		cpu2		cpu3		
126000		1501				1501		
216000		327				327		
408000		86				86		
600000		143				143		
696000		49				49		
816000		38				38		
1008000		90				90		
1200000		697				697		
1416000		1538				1538

Or the cpu is always from cpu3 towards cpu0 (if cpu1 is off, cpu2 and cpu3 must be off as well)?
I think it is the latter, that cpus are turned off from 3 towards 0. Our code does not explicitly turn off cpu2 and cpu3. It just says to use only 2 cpus.
Project Member

Comment 12 by bugdroid1@chromium.org, Jul 11 2017

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/90fd8c3e191c33de5a342c77d059e9ecdbd80bb4

commit 90fd8c3e191c33de5a342c77d059e9ecdbd80bb4
Author: Weidong Guo <weidongg@chromium.org>
Date: Tue Jul 11 00:54:53 2017

Bad format at all_time_in_state

cpu may be offline and not report freq, the all_time_in_state looks like
this:
freq\t\tcpu0\t\tcpu1\t\tcpu2\t\tcpu3\t\t
126000\t\t1501\t\t1501\t\t
216000\t\t327\t\t327\t\t
408000\t\t86\t\t86\t\t

CpuDataCollector did not include the case like this, thus reports error.
This CL fixes this problem and adds unit test.

BUG= 739574 
TEST=CpuDataCollectorTest.ReadCpuFreqAllTimeInStateOff

Change-Id: If4bf584a81eac158c38069fa6228cfc79ffb7665
Reviewed-on: https://chromium-review.googlesource.com/564000
Commit-Queue: Weidong Guo <weidongg@chromium.org>
Reviewed-by: Dan Erat <derat@chromium.org>
Cr-Commit-Position: refs/heads/master@{#485471}
[modify] https://crrev.com/90fd8c3e191c33de5a342c77d059e9ecdbd80bb4/chrome/browser/chromeos/power/cpu_data_collector.cc
[modify] https://crrev.com/90fd8c3e191c33de5a342c77d059e9ecdbd80bb4/chrome/browser/chromeos/power/cpu_data_collector_unittest.cc

Status: Fixed (was: Assigned)
Thanks, I landed a CL to fix that!
Labels: Merge-Request-60
Please cherry-pick to R60, thanks!
Project Member

Comment 15 by sheriffbot@chromium.org, Jul 13 2017

Labels: -Merge-Request-60 Hotlist-Merge-Review Merge-Review-60
This bug requires manual review: We are only 11 days from stable.
Please contact the milestone owner if you have questions.
Owners: amineer@(Android), cmasso@(iOS), josafat@(ChromeOS), bustamante@(Desktop)

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
Labels: -Merge-Review-60 M-60 Merge-Approved-60
Project Member

Comment 17 by sheriffbot@chromium.org, Jul 24 2017

Cc: djkurtz@chromium.org josa...@chromium.org
This issue has been approved for a merge. Please merge the fix to any appropriate branches as soon as possible!

If all merges have been completed, please remove any remaining Merge-Approved labels from this issue.

Thanks for your time! To disable nags, add the Disable-Nags label.

For more details visit https://www.chromium.org/issue-tracking/autotriage - Your friendly Sheriffbot
Project Member

Comment 18 by bugdroid1@chromium.org, Jul 26 2017

Labels: -merge-approved-60 merge-merged-3112
The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/71857c6ca6cb943158fc9640e1273d753f792b62

commit 71857c6ca6cb943158fc9640e1273d753f792b62
Author: Qiang Xu <warx@chromium.org>
Date: Wed Jul 26 17:05:46 2017

[merge to m60] Bad format at all_time_in_state

merge to m60 on behalf of weidongg

cpu may be offline and not report freq, the all_time_in_state looks like
this:
freq\t\tcpu0\t\tcpu1\t\tcpu2\t\tcpu3\t\t
126000\t\t1501\t\t1501\t\t
216000\t\t327\t\t327\t\t
408000\t\t86\t\t86\t\t

CpuDataCollector did not include the case like this, thus reports error.
This CL fixes this problem and adds unit test.

TBR=derat@chromium.org
BUG= 739574 
TEST=CpuDataCollectorTest.ReadCpuFreqAllTimeInStateOff

(cherry picked from commit 90fd8c3e191c33de5a342c77d059e9ecdbd80bb4)

Change-Id: If4bf584a81eac158c38069fa6228cfc79ffb7665
Reviewed-on: https://chromium-review.googlesource.com/564000
Commit-Queue: Weidong Guo <weidongg@chromium.org>
Reviewed-by: Dan Erat <derat@chromium.org>
Cr-Original-Commit-Position: refs/heads/master@{#485471}
Reviewed-on: https://chromium-review.googlesource.com/586731
Reviewed-by: Qiang(Joe) Xu <warx@chromium.org>
Cr-Commit-Position: refs/branch-heads/3112@{#675}
Cr-Branched-From: b6460e24cf59f429d69de255538d0fc7a425ccf9-refs/heads/master@{#474897}
[modify] https://crrev.com/71857c6ca6cb943158fc9640e1273d753f792b62/chrome/browser/chromeos/power/cpu_data_collector.cc
[modify] https://crrev.com/71857c6ca6cb943158fc9640e1273d753f792b62/chrome/browser/chromeos/power/cpu_data_collector_unittest.cc

Comment 19 by dchan@chromium.org, Jan 22 2018

Status: Archived (was: Fixed)

Sign in to add a comment