High frequency browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have stored at least this amount of typing time. - 0 > 0 - JS frame :: mochitests/content/browser/browser/components/places/tests/browser/in
Categories
(Firefox :: Bookmarks & History, defect, P5)
Tracking
()
| Tracking | Status | |
|---|---|---|
| firefox-esr78 | --- | unaffected |
| firefox-esr91 | --- | fixed |
| firefox92 | --- | unaffected |
| firefox93 | --- | fixed |
| firefox94 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: acreskey)
References
(Regression)
Details
(Keywords: intermittent-failure, regression, Whiteboard: [stockwell unknown])
Attachments
(1 file)
|
48 bytes,
text/x-phabricator-request
|
RyanVM
:
approval-mozilla-beta+
RyanVM
:
approval-mozilla-esr91+
|
Details | Review |
Filed by: nbeleuzu [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=343940344&repo=try
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/e28zjWhVSxKob3qsoIFThw/runs/0/artifacts/public/logs/live_backing.log
[task 2021-06-26T14:01:14.943Z] 14:01:14 INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have saved the keypresses into the database - 9 == 9 -
[task 2021-06-26T14:01:14.944Z] 14:01:14 INFO - Buffered messages finished
[task 2021-06-26T14:01:14.944Z] 14:01:14 INFO - TEST-UNEXPECTED-FAIL | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have stored at least this amount of typing time. - 0 > 0 - JS frame :: chrome://mochitests/content/browser/browser/components/places/tests/browser/interactions/head.js :: assertDatabaseValues :: line 116
[task 2021-06-26T14:01:14.944Z] 14:01:14 INFO - Stack trace:
[task 2021-06-26T14:01:14.944Z] 14:01:14 INFO - chrome://mochitests/content/browser/browser/components/places/tests/browser/interactions/head.js:assertDatabaseValues:116
[task 2021-06-26T14:01:14.945Z] 14:01:14 INFO - reload
[task 2021-06-26T14:01:14.945Z] 14:01:14 INFO - GECKO(5280) | console.debug: InteractionsManager: "End of interaction"
[task 2021-06-26T14:01:14.946Z] 14:01:14 INFO - GECKO(5280) | console.debug: InteractionsManager: "Add to store: " ({url:"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html", totalViewTime:17.463638000001083, typingTime:1, keypresses:10, created_at:1624716074794, updated_at:1624716074812})
[task 2021-06-26T14:01:14.946Z] 14:01:14 INFO - GECKO(5280) | console.debug: InteractionsManager: "New interaction" ({isActive:true, url:"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html"})
[task 2021-06-26T14:01:14.946Z] 14:01:14 INFO - GECKO(5280) | console.debug: InteractionsManager: "Storing 1 entries in the database"
[task 2021-06-26T14:01:14.947Z] 14:01:14 INFO - Found 2 interactions:
[task 2021-06-26T14:01:14.947Z] 14:01:14 INFO - [{"url":"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html","keypresses":9,"typingTime":0,"totalViewTime":453},{"url":"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html","keypresses":10,"typingTime":1,"totalViewTime":17}]
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 11•4 years ago
|
||
This went to almost perma-fail after Bug 1717920 landed here.
Andrew, could you please have a look over what's going on here? Thank you.
Updated•4 years ago
|
Comment 12•4 years ago
|
||
Update:
There have been 36 failures within the last 7 days, all on OS X 11 WebRender Shippable opt.
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=350616070&repo=autoland&lineNumber=5254
[task 2021-09-06T00:27:33.634Z] 00:27:33 INFO - TEST-START | browser/components/places/tests/browser/interactions/browser_interactions_typing.js
[task 2021-09-06T00:27:33.634Z] 00:27:33 INFO - GECKO(2676) | console.debug: InteractionsManager: "Database reset"
[task 2021-09-06T00:27:33.636Z] 00:27:33 INFO - GECKO(2676) | console.debug: InteractionsManager: "Database reset"
[task 2021-09-06T00:27:33.639Z] 00:27:33 INFO - GECKO(2676) | console.debug: InteractionsManager: "Tab switched"
[task 2021-09-06T00:27:33.639Z] 00:27:33 INFO - GECKO(2676) | console.debug: InteractionsManager: "No interaction to update"
[task 2021-09-06T00:27:33.655Z] 00:27:33 INFO - GECKO(2676) | console.debug: InteractionsManager: "Tracking a new interaction" ({isActive:true, url:"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html", referrer:(void 0)})
[task 2021-09-06T00:27:33.976Z] 00:27:33 INFO - GECKO(2676) | console.debug: InteractionsManager: "Saw the end of an interaction"
[task 2021-09-06T00:27:33.980Z] 00:27:33 INFO - GECKO(2676) | console.debug: InteractionsManager: "Add to store: " ({url:"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html", referrer:(void 0), totalViewTime:320.4067083333339, typingTime:0, keypresses:0, scrollingTime:0, scrollingDistance:0, created_at:1630888053655, updated_at:1630888053978})
[task 2021-09-06T00:27:33.980Z] 00:27:33 INFO - GECKO(2676) | console.debug: InteractionsManager: "Preparing interaction for storage" ({url:"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html", referrer:(void 0), totalViewTime:320.4067083333339, typingTime:0, keypresses:0, scrollingTime:0, scrollingDistance:0, created_at:1630888053655, updated_at:1630888053978})
[task 2021-09-06T00:27:33.988Z] 00:27:33 INFO - GECKO(2676) | console.debug: InteractionsManager: "Tracking a new interaction" ({isActive:true, url:"https://example.com/browser", referrer:(void 0)})
[task 2021-09-06T00:27:33.989Z] 00:27:33 INFO - GECKO(2676) | console.debug: InteractionsManager: "Storing 1 entries in the database"
[task 2021-09-06T00:27:33.990Z] 00:27:33 INFO - GECKO(2676) | console.debug: SnapshotsManager: "Testing 1 potential snapshots"
[task 2021-09-06T00:27:33.995Z] 00:27:33 INFO - GECKO(2676) | console.debug: InteractionsManager: "Saw the end of an interaction"
<...>
[task 2021-09-06T00:27:39.427Z] 00:27:39 INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have stored at least this amount of typing time. - 1 > 0 -
[task 2021-09-06T00:27:39.427Z] 00:27:39 INFO - reload
[task 2021-09-06T00:27:39.427Z] 00:27:39 INFO - Found 2 interactions:
[task 2021-09-06T00:27:39.427Z] 00:27:39 INFO - [{"url":"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html","referrerUrl":null,"keypresses":9,"typingTime":1,"totalViewTime":706,"scrollingTime":0,"scrollingDistance":0},{"url":"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html","referrerUrl":null,"keypresses":10,"typingTime":0,"totalViewTime":14,"scrollingTime":0,"scrollingDistance":0}]
[task 2021-09-06T00:27:39.427Z] 00:27:39 INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Found the expected number of entries - 2 == 2 -
[task 2021-09-06T00:27:39.428Z] 00:27:39 INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have saved the page into the database - "https://example.com/browser/browser/components/places/tests/browser/keyword_form.html" == "https://example.com/browser/browser/components/places/tests/browser/keyword_form.html" -
[task 2021-09-06T00:27:39.428Z] 00:27:39 INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have saved the keypresses into the database - 9 == 9 -
[task 2021-09-06T00:27:39.428Z] 00:27:39 INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have stored at least this amount of typing time. - 1 > 0 -
[task 2021-09-06T00:27:39.428Z] 00:27:39 INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have saved the page into the database - "https://example.com/browser/browser/components/places/tests/browser/keyword_form.html" == "https://example.com/browser/browser/components/places/tests/browser/keyword_form.html" -
[task 2021-09-06T00:27:39.428Z] 00:27:39 INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have saved the keypresses into the database - 10 == 10 -
[task 2021-09-06T00:27:39.428Z] 00:27:39 INFO - Buffered messages finished
[task 2021-09-06T00:27:39.429Z] 00:27:39 INFO - TEST-UNEXPECTED-FAIL | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have stored at least this amount of typing time. - 0 > 0 - JS frame :: chrome://mochitests/content/browser/browser/components/places/tests/browser/interactions/head.js :: assertDatabaseValues :: line 121
[task 2021-09-06T00:27:39.429Z] 00:27:39 INFO - Stack trace:
[task 2021-09-06T00:27:39.429Z] 00:27:39 INFO - chrome://mochitests/content/browser/browser/components/places/tests/browser/interactions/head.js:assertDatabaseValues:121
[task 2021-09-06T00:27:39.429Z] 00:27:39 INFO - GECKO(2676) | console.debug: InteractionsManager: "Tab switched"
[task 2021-09-06T00:27:39.429Z] 00:27:39 INFO - Leaving test bound test_typing_and_reload
[task 2021-09-06T00:27:39.429Z] 00:27:39 INFO - Entering test bound test_switch_tabs_no_typing
[task 2021-09-06T00:27:39.429Z] 00:27:39 INFO - GECKO(2676) | console.debug: InteractionsManager: "Database reset"
[task 2021-09-06T00:27:39.429Z] 00:27:39 INFO - GECKO(2676) | console.debug: InteractionsManager: "Add to store: " ({url:"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html", referrer:(void 0), totalViewTime:3.7450416666670208, typingTime:0, keypresses:0, scrollingTime:0, scrollingDistance:0, created_at:1630888059288, updated_at:1630888059295})
[task 2021-09-06T00:27:39.430Z] 00:27:39 INFO - GECKO(2676) | console.debug: InteractionsManager: "Preparing interaction for storage" ({url:"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html", referrer:(void 0), totalViewTime:3.7450416666670208, typingTime:0, keypresses:0, scrollingTime:0, scrollingDistance:0, created_at:1630888059288, updated_at:1630888059295})
[task 2021-09-06T00:27:39.430Z] 00:27:39 INFO - GECKO(2676) | console.debug: InteractionsManager: "Tab switched"
[task 2021-09-06T00:27:39.430Z] 00:27:39 INFO - GECKO(2676) | console.debug: InteractionsManager: "No interaction to update"
<...>
[task 2021-09-06T00:27:42.145Z] 00:27:42 INFO - TEST-OK | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | took 8512ms
[task 2021-09-06T00:27:42.148Z] 00:27:42 INFO - GECKO(2676) | console.debug: InteractionsManager: "Tab switched"
[task 2021-09-06T00:27:42.148Z] 00:27:42 INFO - GECKO(2676) | console.debug: InteractionsManager: "No interaction to update"
[task 2021-09-06T00:27:42.149Z] 00:27:42 INFO - checking window state
[task 2021-09-06T00:27:42.150Z] 00:27:42 INFO - TEST-START | browser/components/places/tests/browser/interactions/browser_interactions_view_time.js
Comment 13•4 years ago
|
||
Marco, as the owner of this component, could you help us assign it to someone?
Thank you.
| Comment hidden (Intermittent Failures Robot) |
Comment 15•4 years ago
|
||
I think I might know what's happening here. The typing plus reload is potentially happening too fast, taking less than 1ms to complete. I'll try adding in a small delay and see if that helps.
Updated•4 years ago
|
| Assignee | ||
Comment 16•4 years ago
|
||
Thanks :standard8 - let me know if you want me to take this one over.
| Assignee | ||
Comment 18•4 years ago
|
||
Fix a scenario where it was possible, in automation, for the typing interaction time to report 0ms due to rounding of fractional milliseconds.
In addition, now sending keystrokes individually as this is a better simulation of how users type.
| Assignee | ||
Comment 19•4 years ago
|
||
The patch looks like it resolve the intermittent:
https://treeherder.mozilla.org/jobs?repo=try&revision=3119d0a152cd81f7da4338c9f82de0d714a1436d&selectedTaskRun=ZB2WSWnQSAG_mC8gLmDn3A.0
:CosminS, thanks for flagging this one.
Comment 20•4 years ago
|
||
Comment 21•4 years ago
|
||
| bugherder | ||
| Comment hidden (Intermittent Failures Robot) |
Updated•4 years ago
|
| Assignee | ||
Comment 24•4 years ago
|
||
The fix is extremely low risk to users, so I am in favor of uplifting this.
Comment 25•4 years ago
|
||
OK, could you request the uplift to beta via our bugzilla uplift form? Thanks
| Assignee | ||
Comment 26•4 years ago
|
||
(In reply to Pascal Chevrel:pascalc from comment #25)
OK, could you request the uplift to beta via our bugzilla uplift form? Thanks
Hi Pascal - certainly. Can you point me to where those forms are? I have done that before and I haven't found help on it.
Comment 27•4 years ago
|
||
(In reply to Andrew Creskey [:acreskey] [he/him] from comment #26)
(In reply to Pascal Chevrel:pascalc from comment #25)
OK, could you request the uplift to beta via our bugzilla uplift form? Thanks
Hi Pascal - certainly. Can you point me to where those forms are? I have done that before and I haven't found help on it.
Here is a screencast showing how to trigger the form in Bugzilla UI https://video.chevrel.org/demos/upliftRequestForm.mp4
| Assignee | ||
Comment 28•4 years ago
|
||
Comment on attachment 9240524 [details]
Bug 1718404 - Fix high frequency browser_interactions_typing.js failure r=standard8
Beta/Release Uplift Approval Request
- User impact if declined: There is no impact to users.
The change fixes a rounding error which was making an automated tests fail (for a currently unused feature - user interactions). - Is this code covered by automated tests?: Yes
- Has the fix been verified in Nightly?: Yes
- Needs manual test from QE?: No
- If yes, steps to reproduce:
- List of other uplifts needed: None
- Risk to taking this patch: Low
- Why is the change risky/not risky? (and alternatives if risky): The change is not risky for two reasons:
-The feature, user interactions in history metadata, is disabled by default.
-The change is only to a calculation for that feature and to the automated tests. - String changes made/needed:
| Assignee | ||
Comment 29•4 years ago
|
||
(In reply to Pascal Chevrel:pascalc from comment #27)
(In reply to Andrew Creskey [:acreskey] [he/him] from comment #26)
(In reply to Pascal Chevrel:pascalc from comment #25)
OK, could you request the uplift to beta via our bugzilla uplift form? Thanks
Hi Pascal - certainly. Can you point me to where those forms are? I have done that before and I haven't found help on it.
Here is a screencast showing how to trigger the form in Bugzilla UI https://video.chevrel.org/demos/upliftRequestForm.mp4
Thank you Pascal - the screencast is worth 1000 words.
Comment 30•4 years ago
|
||
Comment on attachment 9240524 [details]
Bug 1718404 - Fix high frequency browser_interactions_typing.js failure r=standard8
Approved for 93.0b7, thanks.
Comment 31•4 years ago
|
||
| bugherder uplift | ||
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
Comment 35•4 years ago
|
||
This is still happening on mozilla-esr91 but now is not that frequent, should we change the status?
Failure log: https://treeherder.mozilla.org/logviewer?job_id=354958035&repo=mozilla-esr91&lineNumber=4598
Push with failures: https://treeherder.mozilla.org/jobs?repo=mozilla-esr91&group_state=expanded&searchStr=os%2Cx%2C10.15%2Cwebrender%2Cshippable%2Copt%2Cmochitests%2Ctest-macosx1015-64-shippable-qr%2Fopt-mochitest-browser-chrome-e10s%2Cbc4&revision=9506ff8bf895cec81d164a9bca7671680b937984&selectedTaskRun=aT0x-gpwTWO5fd7JkPQWwQ.0
Comment 36•4 years ago
|
||
Can you run an uplift this of this onto ESR91 through Try to confirm that the fix works there too?
Comment 37•4 years ago
|
||
Ryan, the issue still reproduces as an almost perma fail
Push to try: https://treeherder.mozilla.org/jobs?repo=try&resultStatus=pending%2Crunning%2Csuccess%2Ctestfailed%2Cbusted%2Cexception%2Crunnable&revision=4b3c8d9587d64c38cb99118d7e87330c7a011a28&searchStr=linux%2C18.04%2Cx64%2Cwebrender%2Casan%2Copt%2Cmochitests%2Cwith%2Csoftware%2Cwebrender%2Cand%2Cfission%2Cenabled%2Ctest-linux1804-64-asan-qr%2Fopt-mochitest-browser-chrome-swr-fis-e10s%2Cbc12&selectedTaskRun=B8Zj3S3MTmipgPgOYIM0EA.0
Comment 38•4 years ago
|
||
We don't run fission tests on ESR91. I don't see any failures on that Try push for non-Fission jobs?
| Comment hidden (Intermittent Failures Robot) |
Comment 40•4 years ago
|
||
Comment on attachment 9240524 [details]
Bug 1718404 - Fix high frequency browser_interactions_typing.js failure r=standard8
ESR Uplift Approval Request
- If this is not a sec:{high,crit} bug, please state case for ESR consideration: frequent test failure
- User impact if declined: none
- Fix Landed on Version: 94
- Risk to taking this patch: Low
- Why is the change risky/not risky? (and alternatives if risky): only rounds up time duration for typing
- String or UUID changes made by this patch: none
Updated•4 years ago
|
Comment 41•4 years ago
|
||
The failures were only on Fission jobs but I thought it worth mentioning them.
Updated•4 years ago
|
Comment 42•4 years ago
|
||
Comment on attachment 9240524 [details]
Bug 1718404 - Fix high frequency browser_interactions_typing.js failure r=standard8
Approved for 91.3esr.
Comment 43•4 years ago
|
||
| bugherder uplift | ||
Description
•