1841701 - Intermittent /websockets/send-many-64K-messages-with-backpressure.any.html | single tracking bug

Status: RESOLVED INCOMPLETE

(Core :: Networking: WebSockets, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=421477340&repo=mozilla-beta
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/VXNUjfSLQCiraqtBkPeAYg/runs/0/artifacts/public/logs/live_backing.log

---

[task 2023-07-04T20:43:39.624Z] 20:43:39     INFO - TEST-START | /websockets/send-many-64K-messages-with-backpressure.any.html?wpt_flags=h2
[task 2023-07-04T20:43:39.627Z] 20:43:39     INFO - Closing window d19cbe29-6799-48c6-9132-0026f4770dc5
[task 2023-07-04T20:44:46.187Z] 20:44:46  WARNING - wptserve (71f21170 - 21) Stream Reset, Thread Closing
[task 2023-07-04T20:44:46.191Z] 20:44:46     INFO - TEST-UNEXPECTED-OK | /websockets/send-many-64K-messages-with-backpressure.any.html?wpt_flags=h2 | expected TIMEOUT
[task 2023-07-04T20:44:46.191Z] 20:44:46     INFO - TEST-INFO expected TIMEOUT | took 66567ms
[task 2023-07-04T20:44:46.192Z] 20:44:46     INFO - PID 3498 | 1688503486191	Marionette	INFO	Stopped listening on port 52119
[task 2023-07-04T20:44:46.361Z] 20:44:46     INFO - Browser exited with return code 0
[task 2023-07-04T20:44:46.362Z] 20:44:46     INFO - Closing logging queue
[task 2023-07-04T20:44:46.363Z] 20:44:46     INFO - queue closed
[task 2023-07-04T20:44:46.398Z] 20:44:46     INFO - Application command: /opt/worker/tasks/task_168850171405871/build/application/Firefox.app/Contents/MacOS/firefox --marionette about:blank -foreground -profile /var/folders/kv/1mdc7wns4pb5h2f26757jxp8000014/T/tmpos9kcufk
[task 2023-07-04T20:44:46.407Z] 20:44:46     INFO - PID 3771 | 1688503383630	Marionette	INFO	Marionette enabled
[task 2023-07-04T20:44:46.407Z] 20:44:46     INFO - PID 3771 | 1688503383902	Marionette	INFO	Listening on port 52600
[task 2023-07-04T20:44:46.408Z] 20:44:46     INFO - PID 3771 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-07-04T20:44:46.408Z] 20:44:46     INFO - PID 3771 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-07-04T20:44:46.409Z] 20:44:46     INFO - PID 3771 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-07-04T20:44:46.409Z] 20:44:46     INFO - PID 3771 | 2023-07-04 20:43:33.506 firefox[3771:120545] Persistent UI failed to open file file:///Users/cltbld/Library/Saved%20Application%20State/org.mozilla.firefox.savedState/window_1.data: No such file or directory (2)
[task 2023-07-04T20:44:46.410Z] 20:44:46     INFO - PID 3771 | console.error: (new Error("Polling for changes failed: Unexpected content-type \"text/plain;charset=US-ASCII\".", "resource://services-settings/remote-settings.sys.mjs", 324))
[task 2023-07-04T20:44:46.410Z] 20:44:46     INFO - Starting runner
[task 2023-07-04T20:44:46.993Z] 20:44:46     INFO - TEST-START | /websockets/send-many-64K-messages-with-backpressure.any.worker.html?wss

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 3

Platform and build breakdown:

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

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1841701&startday=2023-07-03&endday=2023-07-09&tree=all

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 4

Platform and build breakdown:

• macosx1015-64-devedition-qr: 2
  • opt: 2
• macosx1015-64-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1841701&startday=2023-07-17&endday=2023-07-23&tree=all

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 1

Platform and build breakdown:

• windows11-64-2009-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1841701&startday=2023-07-31&endday=2023-08-06&tree=all

Comment 4

[Intermittent Failures Robot]

7 failures in 3341 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 5
• mozilla-release: 1
• try: 1

Platform and build breakdown:

• windows11-64-2009-qr: 5
  • debug: 5
• macosx1015-64-shippable-qr: 1
  • opt: 1
• windows11-32-2009-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1841701&startday=2023-08-07&endday=2023-08-13&tree=all

Comment 5

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-beta: 1
• try: 1

Platform and build breakdown:

• windows11-32-2009-qr: 2
  • debug: 2

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

Comment 6

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 3

Platform and build breakdown:

• windows11-32-2009-qr: 3
  • debug: 3

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

Comment 7

[Randell Jesup [:jesup] (needinfo me)]

@kershaw - did you intend to set a severity/priority for this?

It looks like the previous test blew up wptserv.py, which spent 7 seconds spewing errors before being killed:

sk 2023-08-25T18:14:03.454Z] 18:14:03     INFO - PID 6656 | [Child 724, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:517
[task 2023-08-25T18:14:03.455Z] 18:14:03     INFO - PID 6656 | [Child 724, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:517
[task 2023-08-25T18:14:03.456Z] 18:14:03     INFO - PID 6656 | [Child 724, Main Thread] WARNING: IPC message 'PContent::Msg_CleanupPendingLoadState' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:517
[task 2023-08-25T18:14:03.767Z] 18:14:03  WARNING - wptserve (29b34edc - 1035) Stream Reset, Thread Closing
[task 2023-08-25T18:14:03.798Z] 18:14:03     INFO - .
[task 2023-08-25T18:14:03.798Z] 18:14:03     INFO - TEST-OK | /websockets/binaryType-wrong-value.any.worker.html?wpt_flags=h2 | took 549ms
[task 2023-08-25T18:14:03.803Z] 18:14:03     INFO - TEST-START | /websockets/binaryType-wrong-value.any.html?wpt_flags=h2
[task 2023-08-25T18:14:03.812Z] 18:14:03     INFO - Closing window e11c5207-393d-4fea-90c2-5755ea408487
[task 2023-08-25T18:14:03.939Z] 18:14:03  WARNING - wptserve (29b34edc) Unexpected Error - 
[task 2023-08-25T18:14:03.939Z] 18:14:03  WARNING - Max outbound streams is 100, 0 open
[task 2023-08-25T18:14:03.970Z] 18:14:03     INFO - Test harness output was not a valid structured log message
[task 2023-08-25T18:14:03.970Z] 18:14:03     INFO - Exception in thread Thread-849:
[task 2023-08-25T18:14:03.970Z] 18:14:03     INFO - Traceback (most recent call last):
[task 2023-08-25T18:14:03.972Z] 18:14:03     INFO -   File "Z:\task_169297897581939\build\tests\web-platform\tests\tools\third_party\h2\h2\connection.py", line 224, in process_input
[task 2023-08-25T18:14:03.973Z] 18:14:03  WARNING - wptserve (29b34edc - 507) Stream Reset, Thread Closing
[task 2023-08-25T18:14:03.973Z] 18:14:03     INFO - Test harness output was not a valid structured log message
[task 2023-08-25T18:14:03.973Z] 18:14:03     INFO -     func, target_state = self._transitions[(self.state, input_)]
[task 2023-08-25T18:14:03.973Z] 18:14:03     INFO - KeyError: (<ConnectionState.CLOSED: 3>, <ConnectionInputs.SEND_DATA: 2>)
[task 2023-08-25T18:14:03.974Z] 18:14:03     INFO - During handling of the above exception, another exception occurred:
[task 2023-08-25T18:14:03.974Z] 18:14:03     INFO - Traceback (most recent call last):
[task 2023-08-25T18:14:03.974Z] 18:14:03     INFO -   File "c:\mozilla-build\python3\lib\threading.py", line 973, in _bootstrap_inner
[task 2023-08-25T18:14:03.974Z] 18:14:03     INFO -     self.run()
[task 2023-08-25T18:14:03.975Z] 18:14:03     INFO -   File "c:\mozilla-build\python3\lib\threading.py", line 910, in run
[task 2023-08-25T18:14:03.975Z] 18:14:03     INFO -     self._target(*self._args, **self._kwargs)
[task 2023-08-25T18:14:03.975Z] 18:14:03     INFO -   File "Z:\task_169297897581939\build\tests\web-platform\tests\tools\wptserve\wptserve\server.py", line 546, in _stream_ws_sub_thread
[task 2023-08-25T18:14:03.975Z] 18:14:03     INFO -     connection.end_stream(stream_id)
[task 2023-08-25T18:14:03.975Z] 18:14:03     INFO -   File "Z:\task_169297897581939\build\tests\web-platform\tests\tools\third_party\h2\h2\connection.py", line 882, in end_stream
[task 2023-08-25T18:14:03.976Z] 18:14:03     INFO -     self.state_machine.process_input(ConnectionInputs.SEND_DATA)
[task 2023-08-25T18:14:03.976Z] 18:14:03     INFO -   File "Z:\task_169297897581939\build\tests\web-platform\tests\tools\third_party\h2\h2\connection.py", line 228, in process_input
[task 2023-08-25T18:14:03.976Z] 18:14:03     INFO -     raise ProtocolError(
[task 2023-08-25T18:14:03.976Z] 18:14:03     INFO - h2.exceptions.ProtocolError: Invalid input ConnectionInputs.SEND_DATA in state ConnectionState.CLOSED
[task 2023-08-25T18:14:03.987Z] 18:14:03  WARNING - wptserve (04556efb) Unexpected Error - 
[task 2023-08-25T18:14:03.987Z] 18:14:03  WARNING - Invalid HTTP/2 preamble.
[task 2023-08-25T18:14:03.997Z] 18:14:03  WARNING - wptserve (1369fd0c) Unexpected Error - 
[task 2023-08-25T18:14:03.997Z] 18:14:03  WARNING - Invalid HTTP/2 preamble.
[task 2023-08-25T18:14:03.998Z] 18:14:03  WARNING - wptserve (242d09e8) Unexpected Error - 
[task 2023-08-25T18:14:03.998Z] 18:14:03  WARNING - Invalid HTTP/2 preamble.
[task 2023-08-25T18:14:03.998Z] 18:14:03  WARNING - wptserve (36f0a6b8) Unexpected Error - 
[task 2023-08-25T18:14:03.998Z] 18:14:03  WARNING - Invalid HTTP/2 preamble.
<repeats 1000's of times>

Comment 8

[Randell Jesup [:jesup] (needinfo me)]

Never mind, they are set.

Comment 9

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

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