1717218 - Intermittent browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have saved the keypresses into the database - 43 == 44 - JS frame :: chrome://mochitests/content/browser/browser/components/places/tests/br

Status: RESOLVED FIXED

(Firefox :: Bookmarks & History, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: smolnar [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=343226576&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/FH-GCw7qT-S1YA6s7IYEqA/runs/0/artifacts/public/logs/live_backing.log

---

INFO - TEST-START | browser/components/places/tests/browser/interactions/browser_interactions_typing.js
[task 2021-06-18T13:47:52.023Z] 13:47:52     INFO - GECKO(2257) | console.debug: InteractionsManager: "Reset"
[task 2021-06-18T13:47:52.066Z] 13:47:52     INFO - GECKO(2257) | console.debug: InteractionsManager: "Tab switch notified"
[task 2021-06-18T13:47:52.069Z] 13:47:52     INFO - GECKO(2257) | console.debug: InteractionsManager: "No interaction to update"
[task 2021-06-18T13:47:52.124Z] 13:47:52     INFO - GECKO(2257) | console.debug: InteractionsManager: "Deactivate window"
[task 2021-06-18T13:47:52.126Z] 13:47:52     INFO - GECKO(2257) | console.debug: InteractionsManager: "No interaction to update"
[task 2021-06-18T13:47:52.331Z] 13:47:52     INFO - GECKO(2257) | console.debug: InteractionsManager: "Activate window"
[task 2021-06-18T13:47:52.736Z] 13:47:52     INFO - GECKO(2257) | console.debug: InteractionsManager: "New interaction" ({isActive:true, url:"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html"})
[task 2021-06-18T13:47:53.389Z] 13:47:53     INFO - GECKO(2257) | console.debug: InteractionsManager: "End of interaction"
[task 2021-06-18T13:47:53.393Z] 13:47:53     INFO - GECKO(2257) | console.debug: InteractionsManager: "Would update database: " ({url:"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html", totalViewTime:638.721904, typingTime:0, keypresses:0})
[task 2021-06-18T13:47:53.566Z] 13:47:53     INFO - GECKO(2257) | console.debug: InteractionsManager: "New interaction" ({isActive:true, url:"https://example.com/browser"})
[task 2021-06-18T13:47:53.665Z] 13:47:53     INFO - GECKO(2257) | console.debug: InteractionsManager: "End of interaction"
[task 2021-06-18T13:47:53.667Z] 13:47:53     INFO - GECKO(2257) | console.debug: InteractionsManager: "Would update database: " ({url:"https://example.com/browser", totalViewTime:98.9067329999998, typingTime:0, keypresses:0})
[task 2021-06-18T13:47:53.753Z] 13:47:53     INFO - GECKO(2257) | console.debug: InteractionsManager: "Tab switch notified"
[task 2021-06-18T13:47:53.755Z] 13:47:53     INFO - GECKO(2257) | console.debug: InteractionsManager: "No interaction to update"
[task 2021-06-18T13:47:53.814Z] 13:47:53     INFO - GECKO(2257) | console.debug: InteractionsManager: "Tab switch notified"
[task 2021-06-18T13:47:53.815Z] 13:47:53     INFO - GECKO(2257) | console.debug: InteractionsManager: "No interaction to update"
[task 2021-06-18T13:47:53.922Z] 13:47:53     INFO - GECKO(2257) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-06-18T13:47:53.924Z] 13:47:53     INFO - GECKO(2257) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-06-18T13:47:54.140Z] 13:47:54     INFO - GECKO(2257) | console.debug: InteractionsManager: "New interaction" ({isActive:true, url:"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html"})
[task 2021-06-18T13:47:55.430Z] 13:47:55     INFO - GECKO(2257) | -----------------------------------------------------
[task 2021-06-18T13:47:55.432Z] 13:47:55     INFO - GECKO(2257) | Suppressions used:
<...>
INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have saved the interaction 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-06-18T13:47:59.326Z] 13:47:59     INFO - Buffered messages finished
[task 2021-06-18T13:47:59.329Z] 13:47:59     INFO - TEST-UNEXPECTED-FAIL | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have saved the keypresses into the database - 43 == 44 - JS frame :: chrome://mochitests/content/browser/browser/components/places/tests/browser/interactions/browser_interactions_typing.js :: assertDatabaseValues :: line 70
[task 2021-06-18T13:47:59.330Z] 13:47:59     INFO - Stack trace:
[task 2021-06-18T13:47:59.331Z] 13:47:59     INFO - chrome://mochitests/content/browser/browser/components/places/tests/browser/interactions/browser_interactions_typing.js:assertDatabaseValues:70
[task 2021-06-18T13:47:59.333Z] 13:47:59     INFO - Leaving test bound test_typing_close_tab
[task 2021-06-18T13:47:59.337Z] 13:47:59     INFO - Entering test bound test_single_key_typing_and_delay
[task 2021-06-18T13:47:59.341Z] 13:47:59     INFO - GECKO(2257) | console.debug: InteractionsManager: "Tab switch notified"
[task 2021-06-18T13:47:59.342Z] 13:47:59     INFO - GECKO(2257) | console.debug: InteractionsManager: "No interaction to update"
[task 2021-06-18T13:47:59.344Z] 13:47:59     INFO - GECKO(2257) | -----------------------------------------------------
[task 2021-06-18T13:47:59.346Z] 13:47:59     INFO - GECKO(2257) | Suppressions used:
[task 2021-06-18T13:47:59.347Z] 13:47:59     INFO - GECKO(2257) |   count      bytes template
[task 2021-06-18T13:47:59.351Z] 13:47:59     INFO - GECKO(2257) |      14        448 nsComponentManagerImpl
[task 2021-06-18T13:47:59.353Z] 13:47:59     INFO - GECKO(2257) |       2        288 libfontconfig.so
[task 2021-06-18T13:47:59.355Z] 13:47:59     INFO - GECKO(2257) | -----------------------------------------------------
[task 2021-06-18T13:47:59.358Z] 13:47:59     INFO - GECKO(2257) | console.debug: InteractionsManager: "New interaction" ({isActive:true, url:"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html"})
[task 2021-06-18T13:48:00.055Z] 13:48:00     INFO - GECKO(2257) | -----------------------------------------------------
[task 2021-06-18T13:48:00.056Z] 13:48:00     INFO - GECKO(2257) | Suppressions used:
[task 2021-06-18T13:48:00.057Z] 13:48:00     INFO - GECKO(2257) |   count      bytes template
[task 2021-06-18T13:48:00.058Z] 13:48:00     INFO - GECKO(2257) |      14        448 nsComponentManagerImpl
[task 2021-06-18T13:48:00.059Z] 13:48:00     INFO - GECKO(2257) |       2        288 libfontconfig.so
[task 2021-06-18T13:48:00.059Z] 13:48:00     INFO - GECKO(2257) | -----------------------------------------------------
[task 2021-06-18T13:48:01.576Z] 13:48:01     INFO - GECKO(2257) | console.debug: InteractionsManager: "Tab switch notified"
[task 2021-06-18T13:48:01.579Z] 13:48:01     INFO - GECKO(2257) | console.debug: InteractionsManager: "Would update database: " ({url:"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html", totalViewTime:2373.4752289999997, typingTime:0, keypresses:0})
[task 2021-06-18T13:48:01.649Z] 13:48:01     INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have saved the interaction 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-06-18T13:48:01.653Z] 13:48:01     INFO - Leaving test bound test_single_key_typing_and_delay

Comment 1

[Intermittent Failures Robot]

1 failures in 2888 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-asan: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1717218&startday=2021-06-14&endday=2021-06-20&tree=all

Comment 2

[Andrew Creskey [:acreskey]]

I'm expecting to have this intermittent fixed with Bug 1716606

Comment 3

[BugBot [:suhaib / :marco/ :calixte]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Comment 4

[Marian-Vasile Laza]

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=347795649&repo=autoland&lineNumber=6407

Comment 5

[Intermittent Failures Robot]

1 failures in 2829 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• linux1804-64-asan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1717218&startday=2021-08-02&endday=2021-08-08&tree=all

Comment 6

[Intermittent Failures Robot]

1 failures in 3025 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• macosx1015-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1717218&startday=2021-08-09&endday=2021-08-15&tree=all

Comment 7

[Intermittent Failures Robot]

9 failures in 3084 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1
• autoland: 8

Platform and build breakdown:

• macosx1100-64-shippable-qr: 9
  • opt: 9

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1717218&startday=2021-08-30&endday=2021-09-05&tree=all

Comment 8

[Iulian Moraru]

This started to fail on tier 1: https://treeherder.mozilla.org/logviewer?job_id=351198629&repo=autoland&lineNumber=3490

Comment 9

[Intermittent Failures Robot]

26 failures in 3266 pushes (0.008 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 21
• mozilla-beta: 1
• mozilla-central: 4

Platform and build breakdown:

• macosx1100-64-shippable-qr: 3
  • opt: 3
• linux1804-64-asan-qr: 8
  • opt: 8
• macosx1015-64-qr: 4
  • debug: 2
  • opt: 2
• linux1804-64-qr: 1
  • debug: 1
• linux1804-64-tsan-qr: 9
  • opt: 9
• windows10-64-2004-asan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1717218&startday=2021-09-06&endday=2021-09-12&tree=all

Comment 10

[Andrew Creskey [:acreskey]]

I may have fixed this with Bug 1718404 - verifying now and I'll take care of it if it's not fixed.

Comment 11

[Intermittent Failures Robot]

47 failures in 3375 pushes (0.014 failures/push) were associated with this bug in the last 7 days.

This is the #23 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 33
• try: 1
• mozilla-central: 13

Platform and build breakdown:

• linux1804-64-tsan-qr: 24
  • opt: 24
• linux1804-64-qr: 10
  • debug: 9
  • opt: 1
• linux1804-64-asan-qr: 12
  • opt: 12
• windows10-64-2004-asan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1717218&startday=2021-09-13&endday=2021-09-19&tree=all

Comment 12

[Andreea Pavel [:apavel]]

There are 57 total failures in the last 7 days on

• linux1804-64-asan-qr opt
• linux1804-64-qr debug
• linux1804-64-tsan-qr opt
  Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=352675207&repo=autoland&lineNumber=6829

[task 2021-09-24T20:18:26.413Z] 20:18:26     INFO - TEST-INFO | started process screentopng
[task 2021-09-24T20:18:27.228Z] 20:18:27     INFO - TEST-INFO | screentopng: exit 0
[task 2021-09-24T20:18:27.228Z] 20:18:27     INFO - Buffered messages logged at 20:18:20
[task 2021-09-24T20:18:27.228Z] 20:18:27     INFO - Entering test bound global_setup
[task 2021-09-24T20:18:27.228Z] 20:18:27     INFO - Leaving test bound global_setup
[task 2021-09-24T20:18:27.228Z] 20:18:27     INFO - Entering test bound test_load_and_navigate_away_no_keypresses
[task 2021-09-24T20:18:27.228Z] 20:18:27     INFO - Buffered messages logged at 20:18:22
[task 2021-09-24T20:18:27.228Z] 20:18:27     INFO - Found 1 interactions:
[task 2021-09-24T20:18:27.228Z] 20:18:27     INFO -  [{"url":"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html","referrerUrl":null,"keypresses":0,"typingTime":0,"totalViewTime":314,"scrollingTime":0,"scrollingDistance":0}]
[task 2021-09-24T20:18:27.228Z] 20:18:27     INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Found the expected number of entries - 1 == 1 - 
[task 2021-09-24T20:18:27.228Z] 20:18:27     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-24T20:18:27.228Z] 20:18:27     INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have saved the keypresses into the database - 0 == 0 - 
[task 2021-09-24T20:18:27.228Z] 20:18:27     INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have stored the exact typing time. - 0 == 0 - 
[task 2021-09-24T20:18:27.228Z] 20:18:27     INFO - Found 2 interactions:
[task 2021-09-24T20:18:27.228Z] 20:18:27     INFO -  [{"url":"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html","referrerUrl":null,"keypresses":0,"typingTime":0,"totalViewTime":314,"scrollingTime":0,"scrollingDistance":0},{"url":"https://example.com/browser","referrerUrl":null,"keypresses":0,"typingTime":0,"totalViewTime":208,"scrollingTime":0,"scrollingDistance":0}]
[task 2021-09-24T20:18:27.228Z] 20:18:27     INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Found the expected number of entries - 2 == 2 - 
[task 2021-09-24T20:18:27.232Z] 20:18:27     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-24T20:18:27.234Z] 20:18:27     INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have saved the keypresses into the database - 0 == 0 - 
[task 2021-09-24T20:18:27.235Z] 20:18:27     INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have stored the exact typing time. - 0 == 0 - 
[task 2021-09-24T20:18:27.236Z] 20:18:27     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" == "https://example.com/browser" - 
[task 2021-09-24T20:18:27.238Z] 20:18:27     INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have saved the keypresses into the database - 0 == 0 - 
[task 2021-09-24T20:18:27.241Z] 20:18:27     INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have stored the exact typing time. - 0 == 0 - 
[task 2021-09-24T20:18:27.241Z] 20:18:27     INFO - Buffered messages logged at 20:18:23
[task 2021-09-24T20:18:27.242Z] 20:18:27     INFO - Leaving test bound test_load_and_navigate_away_no_keypresses
[task 2021-09-24T20:18:27.242Z] 20:18:27     INFO - Entering test bound test_load_type_and_navigate_away
[task 2021-09-24T20:18:27.242Z] 20:18:27     INFO - Buffered messages logged at 20:18:26
[task 2021-09-24T20:18:27.243Z] 20:18:27     INFO - Found 1 interactions:
[task 2021-09-24T20:18:27.243Z] 20:18:27     INFO -  [{"url":"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html","referrerUrl":null,"keypresses":43,"typingTime":247,"totalViewTime":1371,"scrollingTime":0,"scrollingDistance":0}]
[task 2021-09-24T20:18:27.244Z] 20:18:27     INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Found the expected number of entries - 1 == 1 - 
[task 2021-09-24T20:18:27.250Z] 20:18:27     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-24T20:18:27.250Z] 20:18:27     INFO - Buffered messages finished
[task 2021-09-24T20:18:27.251Z] 20:18:27     INFO - TEST-UNEXPECTED-FAIL | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have saved the keypresses into the database - 43 == 44 - JS frame :: chrome://mochitests/content/browser/browser/components/places/tests/browser/interactions/head.js :: assertDatabaseValues :: line 107
[task 2021-09-24T20:18:27.251Z] 20:18:27     INFO - Stack trace:
[task 2021-09-24T20:18:27.251Z] 20:18:27     INFO - chrome://mochitests/content/browser/browser/components/places/tests/browser/interactions/head.js:assertDatabaseValues:107
[task 2021-09-24T20:18:27.252Z] 20:18:27     INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have stored at least this amount of typing time. - 247 > 0 - 
[task 2021-09-24T20:18:27.252Z] 20:18:27     INFO - GECKO(8060) | console.debug: InteractionsManager: "Saw the end of an interaction"
[task 2021-09-24T20:18:27.253Z] 20:18:27     INFO - GECKO(8060) | console.debug: InteractionsManager: "No interaction to update"
[task 2021-09-24T20:18:27.253Z] 20:18:27     INFO - GECKO(8060) | console.debug: InteractionsManager: "Add to store: " ({url:"https://example.com/browser", referrer:(void 0), totalViewTime:1150.4076219999988, typingTime:0, keypresses:0, scrollingTime:0, scrollingDistance:0, created_at:1632514705200, updated_at:1632514706453})
[task 2021-09-24T20:18:27.254Z] 20:18:27     INFO - GECKO(8060) | console.debug: InteractionsManager: "Preparing interaction for storage" ({url:"https://example.com/browser", referrer:(void 0), totalViewTime:1150.4076219999988, typingTime:0, keypresses:0, scrollingTime:0, scrollingDistance:0, created_at:1632514705200, updated_at:1632514706453})
[task 2021-09-24T20:18:27.254Z] 20:18:27     INFO - GECKO(8060) | console.debug: InteractionsManager: "Saw the end of an interaction"
[task 2021-09-24T20:18:27.255Z] 20:18:27     INFO - GECKO(8060) | console.debug: InteractionsManager: "No interaction to update"
[task 2021-09-24T20:18:27.255Z] 20:18:27     INFO - GECKO(8060) | console.debug: InteractionsManager: "Storing 1 entries in the database"
[task 2021-09-24T20:18:27.256Z] 20:18:27     INFO - GECKO(8060) | console.debug: SnapshotsManager: "Testing 1 potential snapshots"
[task 2021-09-24T20:18:27.257Z] 20:18:27     INFO - Found 2 interactions:
[task 2021-09-24T20:18:27.257Z] 20:18:27     INFO -  [{"url":"https://example.com/browser/browser/components/places/tests/browser/keyword_form.html","referrerUrl":null,"keypresses":43,"typingTime":247,"totalViewTime":1371,"scrollingTime":0,"scrollingDistance":0},{"url":"https://example.com/browser","referrerUrl":null,"keypresses":0,"typingTime":0,"totalViewTime":1150,"scrollingTime":0,"scrollingDistance":0}]
[task 2021-09-24T20:18:27.257Z] 20:18:27     INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Found the expected number of entries - 2 == 2 - 
[task 2021-09-24T20:18:27.258Z] 20:18:27     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-24T20:18:27.259Z] 20:18:27     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-09-24T20:18:27.264Z] 20:18:27     INFO - TEST-UNEXPECTED-FAIL | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have saved the keypresses into the database - 43 == 44 - JS frame :: chrome://mochitests/content/browser/browser/components/places/tests/browser/interactions/head.js :: assertDatabaseValues :: line 107
[task 2021-09-24T20:18:27.264Z] 20:18:27     INFO - Stack trace:
[task 2021-09-24T20:18:27.264Z] 20:18:27     INFO - chrome://mochitests/content/browser/browser/components/places/tests/browser/interactions/head.js:assertDatabaseValues:107
[task 2021-09-24T20:18:27.265Z] 20:18:27     INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have stored at least this amount of typing time. - 247 > 0 - 
[task 2021-09-24T20:18:27.265Z] 20:18:27     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" == "https://example.com/browser" - 
[task 2021-09-24T20:18:27.266Z] 20:18:27     INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have saved the keypresses into the database - 0 == 0 - 
[task 2021-09-24T20:18:27.266Z] 20:18:27     INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have stored the exact typing time. - 0 == 0 - 

Andrew, can you please take a look?

Comment 13

[Intermittent Failures Robot]

58 failures in 2873 pushes (0.02 failures/push) were associated with this bug in the last 7 days.

This is the #15 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 44
• mozilla-central: 14

Platform and build breakdown:

• linux1804-64-tsan-qr: 26
  • opt: 26
• linux1804-64-qr: 9
  • debug: 9
• linux1804-64-asan-qr: 20
  • opt: 20
• linux1804-64-ccov-qr: 1
  • opt: 1
• macosx1015-64-qr: 1
  • debug: 1
• windows10-64-2004-asan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1717218&startday=2021-09-20&endday=2021-09-26&tree=all

Comment 14

[Intermittent Failures Robot]

17 failures in 528 pushes (0.032 failures/push) were associated with this bug yesterday.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• autoland: 13
• mozilla-central: 4

Platform and build breakdown:

• linux1804-64-tsan-qr: 7
  • opt: 7
• linux1804-64-asan-qr: 5
  • opt: 5
• linux1804-64-qr: 5
  • debug: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1717218&startday=2021-09-30&endday=2021-09-30&tree=all

Comment 15

[Iulian Moraru]

Update:
There have been 64 failures within the last 7 days:
• 19 failures on Linux 18.04 x64 WebRender asan opt
• 14 failures on Linux 18.04 x64 WebRender debug
• 30 failures on linux1804-64-tsan-qr opt
• 1 failures on Windows 10 x64 2004 asan WebRender opt
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=353405806&repo=autoland&lineNumber=9938

[task 2021-10-01T22:53:16.713Z] 22:53:16     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-10-01T22:53:16.713Z] 22:53:16     INFO - Buffered messages finished
[task 2021-10-01T22:53:16.715Z] 22:53:16     INFO - TEST-UNEXPECTED-FAIL | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have saved the keypresses into the database - 43 == 44 - JS frame :: chrome://mochitests/content/browser/browser/components/places/tests/browser/interactions/head.js :: assertDatabaseValues :: line 107
[task 2021-10-01T22:53:16.715Z] 22:53:16     INFO - Stack trace:
[task 2021-10-01T22:53:16.715Z] 22:53:16     INFO - chrome://mochitests/content/browser/browser/components/places/tests/browser/interactions/head.js:assertDatabaseValues:107
[task 2021-10-01T22:53:16.715Z] 22:53:16     INFO - TEST-PASS | browser/components/places/tests/browser/interactions/browser_interactions_typing.js | Should have stored at least this amount of typing time. - 145 > 0 - 

Comment 16

[Marian-Vasile Laza]

Attachment: Bug 1717218 - Disable browser_interactions_typing.js on linux_64_qr_opt for frequent failures. r=#intermittent-reviewers

Comment 17

[Intermittent Failures Robot]

63 failures in 3376 pushes (0.019 failures/push) were associated with this bug in the last 7 days.

This is the #14 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 50
• mozilla-central: 13

Platform and build breakdown:

• linux1804-64-tsan-qr: 33
  • opt: 33
• linux1804-64-asan-qr: 17
  • opt: 17
• linux1804-64-qr: 13
  • debug: 13

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1717218&startday=2021-09-27&endday=2021-10-03&tree=all

Comment 18

[Andrew Creskey [:acreskey]]

I'm starting on this one.

Comment 19

[Intermittent Failures Robot]

16 failures in 676 pushes (0.024 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 9
• mozilla-central: 4
• mozilla-esr91: 2
• mozilla-beta: 1

Platform and build breakdown:

• linux1804-64-tsan-qr: 7
  • opt: 7
• linux1804-64-asan-qr: 5
  • opt: 5
• linux1804-64-qr: 2
  • debug: 2
• macosx1015-64-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1717218&startday=2021-10-04&endday=2021-10-04&tree=all

Comment 20

[Andreea Pavel [:apavel]]

Hi Andrew, this has reached the disable-recommended queue. Can we land the patch until you have the fix or should we wait?

Comment 21

[Andrew Creskey [:acreskey]]

Hi Andreea, thank you for the patience.
I have a test patch pushed, just waiting for results.
I'll be able to answer by end of day.

Comment 22

[Andreea Pavel [:apavel]]

I understand. Thank you for working on this!

Comment 23

[Andrew Creskey [:acreskey]]

Attachment: Bug 1717218 - Fix to intermittent failure in browser_interactions_typing.js

In the scenario where we navigate to a second url immediately after typing we intermittently lose a keystroke on some builds.
I haven't been able to trace down how this happens, however waiting for the next tick in the event loop after each step appears to resolve the intermittent.

Comment 24

[Andrew Creskey [:acreskey]]

Unfortunately, I'm still seeing the occasional intermittent with the above patch.

I've tried quite a few variations and spent as much time debugging this, but it's not clear to me why we're losing a keystroke here.

I'm not sure if it's better to simply remove this subtest for all platforms, or disable browser_interactions_typing.js for the build configuration where it fails?

Comment 25

[Mark Banner (:standard8)]

(In reply to Andrew Creskey [:acreskey] [he/him] from comment #24)

Unfortunately, I'm still seeing the occasional intermittent with the above patch.

I've tried quite a few variations and spent as much time debugging this, but it's not clear to me why we're losing a keystroke here.

I'm not sure if it's better to simply remove this subtest for all platforms, or disable browser_interactions_typing.js for the build configuration where it fails?

If it improves the situation, lets land it for now. I'm wondering if there's something we can do with waitForCondition around the database assertion - maybe custom for this case. If waitForCondition isn't enough it would indicate there's some other issue here.

Comment 26

[Intermittent Failures Robot]

18 failures in 551 pushes (0.033 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 9
• mozilla-central: 9

Platform and build breakdown:

• linux1804-64-qr: 6
  • debug: 6
• linux1804-64-asan-qr: 5
  • opt: 5
• linux1804-64-tsan-qr: 7
  • opt: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1717218&startday=2021-10-08&endday=2021-10-08&tree=all

Comment 27

[Intermittent Failures Robot]

64 failures in 3626 pushes (0.018 failures/push) were associated with this bug in the last 7 days.

This is the #15 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 40
• mozilla-central: 20
• mozilla-esr91: 2
• mozilla-beta: 1
• try: 1

Platform and build breakdown:

• linux1804-64-tsan-qr: 27
  • opt: 27
• linux1804-64-asan-qr: 20
  • opt: 20
• linux1804-64-qr: 13
  • debug: 13
• macosx1015-64-shippable-qr: 2
  • opt: 2
• windows10-64-2004-asan-qr: 1
  • opt: 1
• linux1804-64-ccov-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1717218&startday=2021-10-04&endday=2021-10-10&tree=all

Comment 28

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/cc9b6c2e9afd
Fix to intermittent failure in browser_interactions_typing.js r=Standard8

Comment 29

[Andrew Creskey [:acreskey]]

This patch expected to reduce the failures while I look at this from the database synchronization side.

Comment 30

[Noemi Erli[:noemi_erli]]

https://hg.mozilla.org/mozilla-central/rev/cc9b6c2e9afd

Comment 31

[Alexandru Michis [:malexandru]]

As mentioned in Comment 29, some intermittent failures are still expected to appear, reopening.
https://treeherder.mozilla.org/logviewer?job_id=354598286&repo=autoland&lineNumber=31130

Comment 32

[Intermittent Failures Robot]

17 failures in 748 pushes (0.023 failures/push) were associated with this bug yesterday.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• autoland: 15
• mozilla-central: 2

Platform and build breakdown:

• linux1804-64-asan-qr: 3
  • opt: 3
• linux1804-64-qr: 6
  • debug: 5
  • opt: 1
• linux1804-64-tsan-qr: 4
  • opt: 4
• macosx1015-64-qr: 4
  • debug: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1717218&startday=2021-10-12&endday=2021-10-12&tree=all

Comment 33

[Andrew Creskey [:acreskey]]

Attachment: Bug 1717218 - Intermittent failure in browser_interactions_typing.js

This fixes the root cause of the intermittent failure (missing keystrokes) -- the function to send keys was not strictly synchronous.
We now wait for the input field to be populated before we proceed.

Comment 34

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/696afe3f9f6e
Intermittent failure in browser_interactions_typing.js r=Standard8

Comment 35

[Andreea Pavel [:apavel]]

https://hg.mozilla.org/mozilla-central/rev/696afe3f9f6e

Comment 36

[Intermittent Failures Robot]

44 failures in 3315 pushes (0.013 failures/push) were associated with this bug in the last 7 days.

This is the #20 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 31
• mozilla-central: 11
• elm: 1
• try: 1

Platform and build breakdown:

• linux1804-64-tsan-qr: 18
  • opt: 18
• linux1804-64-qr: 13
  • debug: 12
  • opt: 1
• linux1804-64-asan-qr: 8
  • opt: 8
• macosx1015-64-qr: 5
  • debug: 2
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1717218&startday=2021-10-11&endday=2021-10-17&tree=all

Comment 37

[Andrew Creskey [:acreskey]]

From the graph, I think we got this one.
https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2021-10-11&endday=2021-10-18&tree=trunk&bug=1717218

Comment 38

[Intermittent Failures Robot]

1 failures in 3186 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• linux1804-64-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1717218&startday=2021-10-18&endday=2021-10-24&tree=all

Comment 39

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-esr91/rev/0808f87f80bd
https://hg.mozilla.org/releases/mozilla-esr91/rev/0ce39f45e1a2

Comment 40

[Intermittent Failures Robot]

2 failures in 2992 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 2

Platform and build breakdown:

• linux1804-64-qr: 1
  • debug: 1
• linux1804-64-asan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1717218&startday=2022-02-21&endday=2022-02-27&tree=all