1333312 - Intermittent toolkit/components/aboutperformance/tests/browser/browser_aboutperformance.js | aboutperformance-test:checkSanity error: {"message":"Item li.cpu doesn't match regexp /CPU usage: (\\d+)%/: CPU usage: NaN% (total 0ms).","lineNumber":78,"fileNam

Reporter

Description

•

6 years ago

treeherder

Filed by: philringnalda [at] gmail.com

https://treeherder.mozilla.org/logviewer.html#?job_id=71376232&repo=autoland

https://queue.taskcluster.net/v1/task/b6pIzPhDTwK0V9S9WrdCJA/runs/0/artifacts/public/logs/live_backing.log

Comment hidden (Intermittent Failures Robot)

16 failures in 152 pushes (0.105 failures/push) were associated with this bug yesterday.  

Repository breakdown:
* mozilla-inbound: 9
* autoland: 7

Platform breakdown:
* linux64: 15
* linux32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1333312&startday=2017-01-24&endday=2017-01-24&tree=all

Comment hidden (Intermittent Failures Robot)

38 failures in 749 pushes (0.051 failures/push) were associated with this bug in the last 7 days.  

Repository breakdown:
* autoland: 21
* mozilla-inbound: 16
* mozilla-central: 1

Platform breakdown:
* linux64: 36
* linux32: 2

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1333312&startday=2017-01-23&endday=2017-01-29&tree=all

Geoff Brown [:gbrown]

Comment 3

•

6 years ago

Predominantly happens on linux64/asan.

[task 2017-01-26T01:00:36.927271Z] 01:00:36     INFO - TEST-PASS | toolkit/components/aboutperformance/tests/browser/browser_aboutperformance.js | The title appears in webpages, but not in addons - true == true - 
[task 2017-01-26T01:00:36.934002Z] 01:00:36     INFO - Buffered messages finished
[task 2017-01-26T01:00:36.937977Z] 01:00:36     INFO - TEST-UNEXPECTED-FAIL | toolkit/components/aboutperformance/tests/browser/browser_aboutperformance.js | aboutperformance-test:checkSanity error: {"message":"Item li.cpu doesn't match regexp /CPU usage: (\\d+)%/: CPU usage: NaN% (total 0ms).","lineNumber":78,"fileName":"chrome://mochikit/content/tests/BrowserTestUtils/content-task.js line 52 > eval"} - false == true - JS frame :: chrome://mochitests/content/browser/toolkit/components/aboutperformance/tests/browser/browser_aboutperformance.js :: promiseExpectContent< :: line 229
[task 2017-01-26T01:00:36.940242Z] 01:00:36     INFO - Stack trace:
[task 2017-01-26T01:00:36.942416Z] 01:00:36     INFO -     chrome://mochitests/content/browser/toolkit/components/aboutperformance/tests/browser/browser_aboutperformance.js:promiseExpectContent<:229
[task 2017-01-26T01:00:36.944777Z] 01:00:36     INFO -     test_find_title@chrome://mochitests/content/browser/toolkit/components/aboutperformance/tests/browser/browser_aboutperformance.js:240:25
[task 2017-01-26T01:00:36.946823Z] 01:00:36     INFO -     TaskImpl_run@resource://gre/modules/Task.jsm:319:42
[task 2017-01-26T01:00:36.949151Z] 01:00:36     INFO -     process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:917:23
[task 2017-01-26T01:00:36.952631Z] 01:00:36     INFO -     walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:801:7
[task 2017-01-26T01:00:36.954923Z] 01:00:36     INFO -     Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:734:11
[task 2017-01-26T01:00:36.958039Z] 01:00:36     INFO -     schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:765:7
[task 2017-01-26T01:00:36.960202Z] 01:00:36     INFO -     completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:702:7
[task 2017-01-26T01:00:36.962855Z] 01:00:36     INFO -     TaskImpl_run@resource://gre/modules/Task.jsm:324:15
[task 2017-01-26T01:00:36.965239Z] 01:00:36     INFO -     promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-01-26T01:00:36.971108Z] 01:00:36     INFO -     TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-01-26T01:00:36.973326Z] 01:00:36     INFO -     promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-01-26T01:00:36.977047Z] 01:00:36     INFO -     TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-01-26T01:00:36.979448Z] 01:00:36     INFO -     promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-01-26T01:00:36.981597Z] 01:00:36     INFO -     TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-01-26T01:00:36.983896Z] 01:00:36     INFO -     promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-01-26T01:00:36.986085Z] 01:00:36     INFO -     TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-01-26T01:00:36.988386Z] 01:00:36     INFO -     promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-01-26T01:00:36.991832Z] 01:00:36     INFO -     TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-01-26T01:00:36.993998Z] 01:00:36     INFO -     promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-01-26T01:00:36.996328Z] 01:00:36     INFO -     TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-01-26T01:00:36.999896Z] 01:00:36     INFO -     promise callback*TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:396:7
[task 2017-01-26T01:00:37.001882Z] 01:00:37     INFO -     TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-01-26T01:00:37.004647Z] 01:00:37     INFO -     TaskImpl@resource://gre/modules/Task.jsm:277:3
[task 2017-01-26T01:00:37.010747Z] 01:00:37     INFO -     asyncFunction@resource://gre/modules/Task.jsm:252:14
[task 2017-01-26T01:00:37.013075Z] 01:00:37     INFO -     test_find_title@chrome://mochitests/content/browser/toolkit/components/aboutperformance/tests/browser/browser_aboutperformance.js:240:25
[task 2017-01-26T01:00:37.015254Z] 01:00:37     INFO -     TaskImpl_run@resource://gre/modules/Task.jsm:319:42
[task 2017-01-26T01:00:37.017589Z] 01:00:37     INFO -     TaskImpl@resource://gre/modules/Task.jsm:277:3
[task 2017-01-26T01:00:37.019797Z] 01:00:37     INFO -     asyncFunction@resource://gre/modules/Task.jsm:252:14
[task 2017-01-26T01:00:37.021840Z] 01:00:37     INFO -     Task_spawn@resource://gre/modules/Task.jsm:166:12
[task 2017-01-26T01:00:37.023826Z] 01:00:37     INFO -     TaskImpl_handleResultValue@resource://gre/modules/Task.jsm:389:16
[task 2017-01-26T01:00:37.025851Z] 01:00:37     INFO -     TaskImpl_run@resource://gre/modules/Task.jsm:327:15
[task 2017-01-26T01:00:37.028240Z] 01:00:37     INFO -     process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:917:23
[task 2017-01-26T01:00:37.030683Z] 01:00:37     INFO -     walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:801:7
[task 2017-01-26T01:00:37.033152Z] 01:00:37     INFO -     Promise*scheduleWalkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:734:11
[task 2017-01-26T01:00:37.036369Z] 01:00:37     INFO -     schedulePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:765:7
[task 2017-01-26T01:00:37.038747Z] 01:00:37     INFO -     completePromise@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:702:7
[task 2017-01-26T01:00:37.042037Z] 01:00:37     INFO -     receiveMessage@resource://testing-common/ContentTask.jsm:113:9
[task 2017-01-26T01:00:37.046447Z] 01:00:37     INFO - TEST-PASS | toolkit/components/aboutperformance/tests/browser/browser_aboutperformance.js | The page title appears when about:performance is set to auto-refresh - true == true -

Geoff Brown [:gbrown]

Comment 4

•

6 years ago

The test was updated recently in bug 1328254. Mark, might this be related to your change?

Flags: needinfo?(standard8)

Mark Banner (:standard8)

Comment 5

•

6 years ago

(In reply to Geoff Brown [:gbrown] from comment #4)
> The test was updated recently in bug 1328254. Mark, might this be related to
> your change?

It probably is, since my change got that part of the test actually working.

It looks like the issue is here:

https://dxr.mozilla.org/mozilla-central/rev/1d025ac534a6333a8170a59a95a8a3673d4028ee/toolkit/components/aboutperformance/content/aboutPerformance.js#610

        cachedElements.eltCPU.textContent = `CPU usage: ${Math.ceil(delta.diff.jank.totalCPUTime / delta.diff.deltaT / 10)}%.`;

I'm guessing the `delta.diff.deltaT` is 0, hence causing the NaN.

Unfortunately I don't know enough about the background code to know where delta.diff might be being defined, or why it might be 0. I think Felipe reviewed some of this code, so lets try asking him.

Flags: needinfo?(standard8) → needinfo?(felipc)

:Felipe Gomes (needinfo for replies!)

Assignee

Comment 6

•

6 years ago

I'm gonna pass the question to Yoric

Flags: needinfo?(felipc) → needinfo?(dteller)

David Teller [:Yoric] - still alive but not very active

Comment 7

•

6 years ago

I'm currently at Fosdem, I'll try and look at it by Wednesday.

Comment hidden (Intermittent Failures Robot)

16 failures in 733 pushes (0.022 failures/push) were associated with this bug in the last 7 days.  

Repository breakdown:
* autoland: 12
* mozilla-inbound: 3
* try: 1

Platform breakdown:
* linux64: 16

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1333312&startday=2017-01-30&endday=2017-02-05&tree=all

David Teller [:Yoric] - still alive but not very active

Comment 9

•

6 years ago

I was too optimistic. I'll try and take a look at it next week, but I'm not sure I'll be able to.

:Felipe Gomes (needinfo for replies!)

Assignee

Comment 10

•

6 years ago

Since it's predominantly linux64/asan I suggest we just disable this test there and not spend too much time on it.

Assignee: nobody → felipc

Status: NEW → ASSIGNED

Flags: needinfo?(dteller)

Comment hidden (mozreview-request)

Review commit: https://reviewboard.mozilla.org/r/111320/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/111320/

Mark Banner (:standard8)

Comment 12

•

6 years ago

mozreview-review

Comment on attachment 8835648 [details]
Bug 1333312 - Skip browser_aboutperformance.js on linux64-asan.

https://reviewboard.mozilla.org/r/111320/#review112814

Yeah, lets do it.

Attachment #8835648 - Flags: review?(standard8) → review+

Pulsebot

Comment 13

•

6 years ago

Pushed by felipc@gmail.com:
https://hg.mozilla.org/integration/autoland/rev/20a02827856f
Skip browser_aboutperformance.js on linux64-asan. r=standard8

Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)

Comment 14

•

6 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/20a02827856f

Status: ASSIGNED → RESOLVED

Closed: 6 years ago

status-firefox54: --- → fixed

Resolution: --- → FIXED

Target Milestone: --- → mozilla54

Ryan VanderMeulen [:RyanVM]

Updated

•

6 years ago

status-firefox52: --- → unaffected

status-firefox53: --- → affected

Ryan VanderMeulen [:RyanVM]

Comment 15

•

6 years ago

bugherderuplift

https://hg.mozilla.org/releases/mozilla-aurora/rev/b7af012f09fe

status-firefox53: affected → fixed

Flags: in-testsuite-

Joel Maher ( :jmaher ) (UTC -8)

Updated

•

6 years ago

Whiteboard: [stockwell disabled]

Bugzilla

Quick Search

Intermittent toolkit/components/aboutperformance/tests/browser/browser_aboutperformance.js | aboutperformance-test:checkSanity error: {"message":"Item li.cpu doesn't match regexp /CPU usage: (\\d+)%/: CPU usage: NaN% (total 0ms).","lineNumber":78,"fileNam

Categories

(Toolkit :: Performance Monitoring, defect)

Tracking

()

People

(Reporter: intermittent-bug-filer, Assigned: Felipe)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell disabled])

Crash Data

Security

(public)

User Story

Attachments

(1 file)

Description

Comment 1

Comment 2

Comment 3

Comment 4

Comment 5

Comment 6

Comment 7

Comment 8

Comment 9

Comment 10

Comment 11

Comment 12

Comment 13

Comment 14

Updated

Comment 15

Updated