Closed Bug 1572963 Opened 7 years ago Closed 6 years ago

High frequency TEST-UNEXPECTED-FAIL | dom/base/test/browser_use_counters.js | document counts for PROPERTY_FILL after are correct - Got 28, expected 21 when Gecko 70 merges to Beta on 2019-08-26

Categories

(Core :: DOM: Core & HTML, defect, P1)

Product:
Core
Component:
DOM: Core & HTML
Type:
defect

Tracking

()

Status:
VERIFIED FIXED
Tracking Flags:
Tracking Status
firefox-esr60 --- unaffected
firefox-esr68 --- unaffected
firefox68 --- unaffected
firefox69 --- unaffected
firefox70 + verified

People

(Reporter: malexandru, Assigned: edgar)

References

Details

Central as Late Beta:
https://treeherder.mozilla.org/#/jobs?repo=try&group_state=expanded&selectedJob=260929230&resultStatus=pending%2Crunning%2Ctestfailed%2Cbusted%2Cexception%2Cusercancel%2Crunnable&revision=06ed3122739098cd898d5af2926a71b55a96144a&searchStr=%28bc2

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=260929230&repo=try&lineNumber=42894

[task 2019-08-10T13:21:34.141Z] 13:21:34 INFO - TEST-PASS | dom/base/test/browser_use_counters.js | top level document counts are correct -
[task 2019-08-10T13:21:34.141Z] 13:21:34 INFO - checking file_use_counter_svg_currentScale.svg with histogram SVGSVGELEMENT_CURRENTSCALE_getter
[task 2019-08-10T13:21:34.142Z] 13:21:34 INFO - Buffered messages logged at 13:21:29
[task 2019-08-10T13:21:34.142Z] 13:21:34 INFO - TEST-PASS | dom/base/test/browser_use_counters.js | page counts for SVGSVGELEMENT_CURRENTSCALE_getter after are correct -
[task 2019-08-10T13:21:34.143Z] 13:21:34 INFO - TEST-PASS | dom/base/test/browser_use_counters.js | top level document counts are correct -
[task 2019-08-10T13:21:34.143Z] 13:21:34 INFO - checking file_use_counter_svg_currentScale.svg with histogram SVGSVGELEMENT_CURRENTSCALE_setter
[task 2019-08-10T13:21:34.144Z] 13:21:34 INFO - Buffered messages logged at 13:21:31
[task 2019-08-10T13:21:34.144Z] 13:21:34 INFO - TEST-PASS | dom/base/test/browser_use_counters.js | page counts for SVGSVGELEMENT_CURRENTSCALE_setter after are correct -
[task 2019-08-10T13:21:34.145Z] 13:21:34 INFO - TEST-PASS | dom/base/test/browser_use_counters.js | top level document counts are correct -
[task 2019-08-10T13:21:34.145Z] 13:21:34 INFO - checking file_use_counter_svg_getElementById.svg as image with histogram PROPERTY_FILL
[task 2019-08-10T13:21:34.145Z] 13:21:34 INFO - Buffered messages logged at 13:21:34
[task 2019-08-10T13:21:34.146Z] 13:21:34 INFO - TEST-PASS | dom/base/test/browser_use_counters.js | page counts for PROPERTY_FILL after are correct -
[task 2019-08-10T13:21:34.146Z] 13:21:34 INFO - Buffered messages finished
[task 2019-08-10T13:21:34.147Z] 13:21:34 INFO - TEST-UNEXPECTED-FAIL | dom/base/test/browser_use_counters.js | document counts for PROPERTY_FILL after are correct - Got 28, expected 21
[task 2019-08-10T13:21:34.147Z] 13:21:34 INFO - Stack trace:
[task 2019-08-10T13:21:34.147Z] 13:21:34 INFO - chrome://mochikit/content/browser-test.js:test_is:1591
[task 2019-08-10T13:21:34.147Z] 13:21:34 INFO - chrome://mochitests/content/browser/dom/base/test/browser_use_counters.js:check_use_counter_img:347
[task 2019-08-10T13:21:34.147Z] 13:21:34 INFO - TEST-PASS | dom/base/test/browser_use_counters.js | top level document counts are correct -
[task 2019-08-10T13:21:34.148Z] 13:21:34 INFO - TEST-PASS | dom/base/test/browser_use_counters.js | document counts are correct -
[task 2019-08-10T13:21:34.148Z] 13:21:34 INFO - checking file_use_counter_svg_currentScale.svg as image with histogram PROPERTY_FILL
[task 2019-08-10T13:21:34.148Z] 13:21:34 INFO - GECKO(6220) | ++DOCSHELL 0000025FC6C0C000 == 4 [pid = 8284] [id = {7590e446-a64e-4d04-8103-1a6c688c9bf4}]
[task 2019-08-10T13:21:34.148Z] 13:21:34 INFO - GECKO(6220) | ++DOMWINDOW == 17 (0000025FBED992E0) [pid = 8284] [serial = 113] [outer = 0000000000000000]
[task 2019-08-10T13:21:34.148Z] 13:21:34 INFO - GECKO(6220) | ++DOMWINDOW == 18 (0000025FC5272C00) [pid = 8284] [serial = 114] [outer = 0000025FBED992E0]
[task 2019-08-10T13:21:34.148Z] 13:21:34 INFO - GECKO(6220) | [Child 8284, Main Thread] WARNING: No active window: file z:/build/build/src/js/xpconnect/src/XPCJSContext.cpp, line 664
[task 2019-08-10T13:21:34.213Z] 13:21:34 INFO - GECKO(6220) | [Child 8284, Main Thread] WARNING: No active window: file z:/build/build/src/js/xpconnect/src/XPCJSContext.cpp, line 664
[task 2019-08-10T13:21:34.232Z] 13:21:34 INFO - GECKO(6220) | ++DOMWINDOW == 19 (0000025FCD7D8800) [pid = 8284] [serial = 115] [outer = 0000025FBED992E0]
[task 2019-08-10T13:21:34.242Z] 13:21:34 INFO - GECKO(6220) | ++DOCSHELL 0000025FC6C74800 == 5 [pid = 8284] [id = {4446509f-f711-4251-934f-622323757dd9}]
[task 2019-08-10T13:21:34.242Z] 13:21:34 INFO - GECKO(6220) | ++DOMWINDOW == 20 (0000025FBED994C0) [pid = 8284] [serial = 116] [outer = 0000000000000000]
[task 2019-08-10T13:21:34.247Z] 13:21:34 INFO - GECKO(6220) | ++DOMWINDOW == 21 (0000025FCE30CC00) [pid = 8284] [serial = 117] [outer = 0000025FBED994C0]
[task 2019-08-10T13:21:34.252Z] 13:21:34 INFO - GECKO(6220) | [Parent 11320, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file z:/build/build/src/obj-firefox/dist/include\mozilla/RangeBoundary.h, line 79
[task 2019-08-10T13:21:34.252Z] 13:21:34 INFO - GECKO(6220) | [Parent 11320, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file z:/build/build/src/obj-firefox/dist/include\mozilla/RangeBoundary.h, line 79
[task 2019-08-10T13:21:34.352Z] 13:21:34 INFO - GECKO(6220) | [Parent 11320, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file z:/build/build/src/obj-firefox/dist/include\mozilla/RangeBoundary.h, line 79
[task 2019-08-10T13:21:34.352Z] 13:21:34 INFO - GECKO(6220) | [Parent 11320, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file z:/build/build/src/obj-firefox/dist/include\mozilla/RangeBoundary.h, line 79
[task 2019-08-10T13:21:34.357Z] 13:21:34 INFO - GECKO(6220) | [Child 8284, Main Thread] WARNING: No active window: file z:/build/build/src/js/xpconnect/src/XPCJSContext.cpp, line 664
[task 2019-08-10T13:21:34.585Z] 13:21:34 INFO - GECKO(6220) | --DOMWINDOW == 20 (0000025FC6A87400) [pid = 8284] [serial = 98] [outer = 0000000000000000] [url = http://example.com/browser/dom/base/test/file_use_counter_outer.html]
[task 2019-08-10T13:21:34.585Z] 13:21:34 INFO - GECKO(6220) | --DOMWINDOW == 19 (0000025FCD71E400) [pid = 8284] [serial = 101] [outer = 0000000000000000] [url = http://example.com/browser/dom/base/test/file_use_counter_svg_currentScale.svg]
[task 2019-08-10T13:21:34.586Z] 13:21:34 INFO - GECKO(6220) | --DOMWINDOW == 18 (0000025FC6C39800) [pid = 8284] [serial = 100] [outer = 0000000000000000] [url = about:blank]
[task 2019-08-10T13:21:34.586Z] 13:21:34 INFO - GECKO(6220) | --DOMWINDOW == 17 (0000025FBED78C00) [pid = 8284] [serial = 103] [outer = 0000000000000000] [url = about:blank]
[task 2019-08-10T13:21:34.586Z] 13:21:34 INFO - GECKO(6220) | --DOMWINDOW == 16 (0000025FCD720800) [pid = 8284] [serial = 106] [outer = 0000000000000000] [url = about:blank]
[task 2019-08-10T13:21:34.586Z] 13:21:34 INFO - GECKO(6220) | --DOCSHELL 0000025FC6C74800 == 4 [pid = 8284] [id = {4446509f-f711-4251-934f-622323757dd9}] [url = about:blank]
[task 2019-08-10T13:21:34.586Z] 13:21:34 INFO - GECKO(6220) | --DOCSHELL 0000025FC6C15000 == 3 [pid = 8284] [id = {da566570-f8c2-4013-a4c4-23dc194fa435}] [url = about:blank]
[task 2019-08-10T13:21:34.587Z] 13:21:34 INFO - GECKO(6220) | --DOCSHELL 0000025FC6C0C000 == 2 [pid = 8284] [id = {7590e446-a64e-4d04-8103-1a6c688c9bf4}] [url = http://example.com/browser/dom/base/test/file_use_counter_outer.html]
[task 2019-08-10T13:21:34.587Z] 13:21:34 INFO - GECKO(6220) | --DOCSHELL 0000025FBED44000 == 1 [pid = 8284] [id = {39cf60c6-7222-4f16-9854-182698170185}] [url = http://example.com/browser/dom/base/test/file_use_counter_outer.html]
[task 2019-08-10T13:21:34.633Z] 13:21:34 INFO - GECKO(6220) | --DOMWINDOW == 15 (0000025FBED98200) [pid = 8284] [serial = 102] [outer = 0000000000000000] [url = http://example.com/browser/dom/base/test/file_use_counter_outer.html]
[task 2019-08-10T13:21:34.633Z] 13:21:34 INFO - GECKO(6220) | --DOMWINDOW == 14 (0000025FBED98980) [pid = 8284] [serial = 105] [outer = 0000000000000000] [url = http://example.com/browser/dom/base/test/file_use_counter_svg_currentScale.svg]
[task 2019-08-10T13:21:36.172Z] 13:21:36 INFO - TEST-PASS | dom/base/test/browser_use_counters.js | page counts for PROPERTY_FILL after are correct -
[task 2019-08-10T13:21:36.172Z] 13:21:36 INFO - TEST-PASS | dom/base/test/browser_use_counters.js | document counts for PROPERTY_FILL after are correct -
[task 2019-08-10T13:21:36.172Z] 13:21:36 INFO - TEST-PASS | dom/base/test/browser_use_counters.js | top level document counts are correct -
[task 2019-08-10T13:21:36.172Z] 13:21:36 INFO - TEST-PASS | dom/base/test/browser_use_counters.js | document counts are correct -

Hsin-Yi, can you help find an owner for this issue? thanks!

tracking-firefox70: ? → +
Flags: needinfo?(htsai)
Priority: -- → P1
Assignee: nobody → echen
Flags: needinfo?(htsai)

I could reproduced this on try with enabling logs for use counters, https://treeherder.mozilla.org/#/jobs?repo=try&exclusion_profile=false&group_state=expanded&selectedJob=261568481&tier=1&revision=d4a97a49541e0488120c0787c2dd00fdff46d603.

The unexpected use counters for css fill property is from resource://activity-stream...

[task 2019-08-14T12:13:44.463Z] 12:13:44 INFO - GECKO(10268) | -- Use counters for resource://activity-stream/data/content/assets/glyph-topsites-16.svg --
[task 2019-08-14T12:13:44.463Z] 12:13:44 INFO - GECKO(10268) | USE_COUNTER2_PROPERTY_FILL_DOCUMENT: 1
[task 2019-08-14T12:13:44.464Z] 12:13:44 INFO - GECKO(10268) | -- Use counters for resource://activity-stream/data/content/assets/glyph-dismiss-16.svg --
[task 2019-08-14T12:13:44.465Z] 12:13:44 INFO - GECKO(10268) | USE_COUNTER2_PROPERTY_FILL_DOCUMENT: 1
[task 2019-08-14T12:13:44.465Z] 12:13:44 INFO - GECKO(10268) | -- Use counters for resource://activity-stream/data/content/assets/glyph-search-16.svg --
[task 2019-08-14T12:13:44.465Z] 12:13:44 INFO - GECKO(10268) | USE_COUNTER2_PROPERTY_FILL_DOCUMENT: 1
[task 2019-08-14T12:13:44.465Z] 12:13:44 INFO - GECKO(10268) | -- Use counters for resource://activity-stream/data/content/assets/glyph-pin-12.svg --
[task 2019-08-14T12:13:44.467Z] 12:13:44 INFO - GECKO(10268) | USE_COUNTER2_PROPERTY_FILL_DOCUMENT: 1
[task 2019-08-14T12:13:44.468Z] 12:13:44 INFO - GECKO(10268) | -- Use counters for resource://activity-stream/data/content/assets/glyph-edit-16.svg --
[task 2019-08-14T12:13:44.468Z] 12:13:44 INFO - GECKO(10268) | USE_COUNTER2_PROPERTY_FILL_DOCUMENT: 1
[task 2019-08-14T12:13:44.469Z] 12:13:44 INFO - GECKO(10268) | -- Use counters for resource://activity-stream/data/content/assets/glyph-highlights-16.svg --
[task 2019-08-14T12:13:44.469Z] 12:13:44 INFO - GECKO(10268) | USE_COUNTER2_PROPERTY_FILL_DOCUMENT: 1
[task 2019-08-14T12:13:44.470Z] 12:13:44 INFO - GECKO(10268) | -- Use counters for resource://activity-stream/data/content/assets/glyph-arrowhead-down-12.svg --
[task 2019-08-14T12:13:44.470Z] 12:13:44 INFO - GECKO(10268) | USE_COUNTER2_PROPERTY_FILL_DOCUMENT: 1

It seems all about the timing: test expects only one usage increasing after loading http://example.com/browser/dom/base/test/file_use_counter_svg_getElementById.svg, but we also report usage for resource://activity-stream... during that period, so test get 7 more usages..

We currently don't count the usage of chrome://* or about:*, maybe we don't need to count the usage of resource:, either?

(In reply to Edgar Chen [:edgar] from comment #3)

We currently don't count the usage of chrome://* or about:*, maybe we don't need to count the usage of resource:, either?

Filed bug 1573842.

Depends on: 1573842

bug 1573842 should also fix this.

Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.