1638547 - Intermittent TEST-UNEXPECTED-TIMEOUT | /webrtc/getstats.html | Can get stats from a basic WebRTC call. - Test timed out

Status: RESOLVED INCOMPLETE

(Core :: WebRTC, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: cbrindusan [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=302575968&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/VJMXqKDxQLq-PNI3dvfOnA/runs/0/artifacts/public/logs/live_backing.log

---

[task 2020-05-16T11:56:01.920Z] 11:56:01 INFO - TEST-START | /workers/WorkerNavigator_onLine.htm
[task 2020-05-16T11:56:01.925Z] 11:56:01 INFO - Closing window 180
[task 2020-05-16T11:56:02.000Z] 11:56:02 INFO - PID 5876 | [Child 7612: Main Thread]: D/DataChannel 000001862F528660: Close()ing 000001862ED41E50
[task 2020-05-16T11:56:02.001Z] 11:56:02 INFO - PID 5876 | [Child 7612: Main Thread]: D/DataChannel Connection 000001862ED35400/Channel 000001862ED41E50: Closing stream 1
[task 2020-05-16T11:56:02.001Z] 11:56:02 INFO - PID 5876 | [Child 7612: Main Thread]: D/DataChannel Connection 000001862ED35400: Resetting outgoing stream 1
[task 2020-05-16T11:56:02.001Z] 11:56:02 INFO - PID 5876 | [Child 7612: Main Thread]: D/DataChannel Connection 000001862ED35400: Sending outgoing stream reset for 1 streams
[task 2020-05-16T11:56:02.001Z] 11:56:02 INFO - PID 5876 | [Child 7612: Main Thread]: E/DataChannel ***failed: setsockopt RESET, errno 2
[task 2020-05-16T11:56:02.001Z] 11:56:02 INFO - PID 5876 | [Child 7612: Main Thread]: D/DataChannel DataChannelConnection labeled channel(000001862ED41E50) (stream 1) changing ready state CONNECTING -> CLOSING
[task 2020-05-16T11:56:02.079Z] 11:56:02 INFO - PID 5876 | [Child 7612: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2637: GetStats: Found no pipelines matching selector.
[task 2020-05-16T11:56:02.079Z] 11:56:02 INFO - PID 5876 | [Child 7612: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2637: GetStats: Found no pipelines matching selector.
[task 2020-05-16T11:56:02.111Z] 11:56:02 INFO -
[task 2020-05-16T11:56:02.111Z] 11:56:02 INFO - TEST-UNEXPECTED-TIMEOUT | /webrtc/getstats.html | Can get stats from a basic WebRTC call. - Test timed out

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• windows10-64-shippable-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1638547&startday=2020-05-11&endday=2020-05-17&tree=all

Comment 2

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

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

Comment 3

[Andreea Pavel [:apavel]]

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

[task 2020-12-16T12:39:23.722Z] 12:39:23 INFO - TEST-PASS | /webrtc/RTCTrackEvent-fire.html | When a=msid is absent, the track should still be associated with a stream
[task 2020-12-16T12:39:23.722Z] 12:39:23 INFO - TEST-PASS | /webrtc/RTCTrackEvent-fire.html | Source-level msid should be ignored if media-level msid is present
[task 2020-12-16T12:39:23.722Z] 12:39:23 INFO - TEST-PASS | /webrtc/RTCTrackEvent-fire.html | Source-level msid should be parsed if media-level msid is absent
[task 2020-12-16T12:39:23.722Z] 12:39:23 INFO - TEST-PASS | /webrtc/RTCTrackEvent-fire.html | Source-level msid should be ignored, or an error should be thrown, if a different media-level msid is present
[task 2020-12-16T12:39:23.722Z] 12:39:23 INFO - TEST-PASS | /webrtc/RTCTrackEvent-fire.html | stream ids should be found even if msid-semantic is absent
[task 2020-12-16T12:39:23.722Z] 12:39:23 INFO - TEST-PASS | /webrtc/RTCTrackEvent-fire.html | a=msid:- should result in a track event with no streams
[task 2020-12-16T12:39:23.722Z] 12:39:23 INFO - TEST-PASS | /webrtc/RTCTrackEvent-fire.html | Duplicate a=msid should result in a track event with one stream
[task 2020-12-16T12:39:23.723Z] 12:39:23 INFO - TEST-PASS | /webrtc/RTCTrackEvent-fire.html | Applying a remote description with removed msid should trigger firing a removetrack event on the corresponding stream
[task 2020-12-16T12:39:23.723Z] 12:39:23 INFO - TEST-PASS | /webrtc/RTCTrackEvent-fire.html | Applying a remote description with a new msid should trigger firing an event with populated streams
[task 2020-12-16T12:39:23.723Z] 12:39:23 INFO - TEST-FAIL | /webrtc/datachannel-emptystring.html | Can send empty strings across a WebRTC data channel. - The operation failed for an operation-specific reason
[task 2020-12-16T12:39:23.723Z] 12:39:23 INFO - onSendChannelOpen<@http://web-platform.test:8000/webrtc/datachannel-emptystring.html:38:17
[task 2020-12-16T12:39:23.723Z] 12:39:23 INFO - Test.prototype.step@http://web-platform.test:8000/resources/testharness.js:2044:25
[task 2020-12-16T12:39:23.723Z] 12:39:23 INFO - Test.prototype.step_func/<@http://web-platform.test:8000/resources/testharness.js:2069:35
[task 2020-12-16T12:39:23.723Z] 12:39:23 INFO - TEST-UNEXPECTED-TIMEOUT | /webrtc/getstats.html | Can get stats from a basic WebRTC call. - Test timed out
[task 2020-12-16T12:39:23.723Z] 12:39:23 INFO - TEST-INFO | expected FAIL
[task 2020-12-16T12:39:23.724Z] 12:39:23 INFO - TEST-UNEXPECTED-TIMEOUT | /webrtc/getstats.html | expected OK
[task 2020-12-16T12:39:23.724Z] 12:39:23 INFO - TEST-INFO took 10139ms
[task 2020-12-16T12:39:23.730Z] 12:39:23 INFO - PID 5064 | 1608122363722 Marionette INFO Stopped listening on port 49875
[task 2020-12-16T12:39:23.799Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2089: CloseInt: Closing PeerConnectionImpl {679c2616-6b17-4398-b027-d73d2e45961d}; ending call
[task 2020-12-16T12:39:23.800Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: I/jsep [{679c2616-6b17-4398-b027-d73d2e45961d} 1608122353725000 (id=49392123912 url=http://web-platform.test:8000/webrtc/getstats.html)]: stable -> closed
[task 2020-12-16T12:39:23.803Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2095: CloseInt: Destroying DataChannelConnection 0C5D2D20 for {679c2616-6b17-4398-b027-d73d2e45961d}
[task 2020-12-16T12:39:23.807Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel Destroying DataChannelConnection 0C5D2D20
[task 2020-12-16T12:39:23.807Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel Closing all channels (connection 0C5D2D20)
[task 2020-12-16T12:39:23.807Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel DataChannelConnection labeled transport_0 (0C5D2D20) switching connection state CONNECTING -> CLOSED
[task 2020-12-16T12:39:23.807Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel Connection 0C5D2D20/Channel 0E8F2240: Closing stream 1
[task 2020-12-16T12:39:23.808Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel Removing channel 1 : 0E8F2240
[task 2020-12-16T12:39:23.808Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel Channel already closing/closed (2)
[task 2020-12-16T12:39:23.812Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel closing pending channel 0E8F2240, stream 1
[task 2020-12-16T12:39:23.812Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel Connection 0C5D2D20/Channel 0E8F2240: Closing stream 1
[task 2020-12-16T12:39:23.812Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel Removing channel 1 : 0E8F2240
[task 2020-12-16T12:39:23.812Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel Channel already closing/closed (2)
[task 2020-12-16T12:39:23.813Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel Connection 0C5D2D20: Sending outgoing stream reset for 1 streams
[task 2020-12-16T12:39:23.815Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: E/DataChannel ***failed: setsockopt RESET, errno 2
[task 2020-12-16T12:39:23.815Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel Clearing resets for 1 streams
[task 2020-12-16T12:39:23.815Z] 12:39:23 INFO - PID 5064 | [Child 3544: Socket Thread]: D/DataChannel Deregistered 00000003 from the SCTP stack.
[task 2020-12-16T12:39:23.817Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2089: CloseInt: Closing PeerConnectionImpl {d66e22c5-4e7b-459b-b8b3-61cf0d9a1fa9}; ending call
[task 2020-12-16T12:39:23.819Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: I/jsep [{d66e22c5-4e7b-459b-b8b3-61cf0d9a1fa9} 1608122353735000 (id=49392123912 url=http://web-platform.test:8000/webrtc/getstats.html)]: stable -> closed
[task 2020-12-16T12:39:23.822Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2095: CloseInt: Destroying DataChannelConnection 0C5D2E90 for {d66e22c5-4e7b-459b-b8b3-61cf0d9a1fa9}
[task 2020-12-16T12:39:23.822Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel Destroying DataChannelConnection 0C5D2E90
[task 2020-12-16T12:39:23.823Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel Closing all channels (connection 0C5D2E90)
[task 2020-12-16T12:39:23.825Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel DataChannelConnection labeled transport_0 (0C5D2E90) switching connection state CONNECTING -> CLOSED
[task 2020-12-16T12:39:23.825Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel Connection 0C5D2E90: Sending outgoing stream reset for 0 streams
[task 2020-12-16T12:39:23.826Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel No streams to reset
[task 2020-12-16T12:39:23.828Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel Deleting DataChannelConnection 0C5D2D20
[task 2020-12-16T12:39:23.829Z] 12:39:23 INFO - PID 5064 | [Child 3544: Socket Thread]: D/DataChannel Deregistered 00000004 from the SCTP stack.
[task 2020-12-16T12:39:23.829Z] 12:39:23 INFO - PID 5064 | [Child 3544: Main Thread]: D/DataChannel Deleting DataChannelConnection 0C5D2E90
[task 2020-12-16T12:39:24.063Z] 12:39:24 INFO - Browser exited with return code 0
[task 2020-12-16T12:39:24.063Z] 12:39:24 INFO - PROCESS LEAKS None
[task 2020-12-16T12:39:24.067Z] 12:39:24 INFO - Closing logging queue
[task 2020-12-16T12:39:24.067Z] 12:39:24 INFO - queue closed
[task 2020-12-16T12:39:24.187Z] 12:39:24 INFO - Application command: Z:\task_1608121143\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_1608121143\AppData\Local\Temp\tmpjp5e5nli
[task 2020-12-16T12:39:24.193Z] 12:39:24 INFO - Starting runner
[task 2020-12-16T12:39:25.697Z] 12:39:25 INFO - PID 7336 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new Error("", "(unknown module)"))
[task 2020-12-16T12:39:26.571Z] 12:39:26 INFO - PID 7336 | 1608122366570 Marionette INFO Listening on port 50176
[task 2020-12-16T12:39:26.990Z] 12:39:26 INFO - PID 7336 | 1608122366989 Marionette ERROR [20] No reply from Marionette:Register
[task 2020-12-16T12:39:27.062Z] 12:39:27 INFO - PID 7336 | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'MarionetteEvents'

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 5
• try: 1

Platform breakdown:

• windows7-32: 5
• windows7-32-shippable: 1

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

Comment 5

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1
• autoland: 1

Platform breakdown:

• windows7-32-shippable: 1
• windows7-32: 1

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

Comment 6

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 2

Platform breakdown:

• windows7-32: 2

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

Comment 7

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1
• mozilla-central: 1

Platform and build breakdown:

• windows7-32: 1
  • opt: 1
• windows7-32-shippable: 1
  • opt: 1

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

Comment 8

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows7-32: 1
  • opt: 1

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

Comment 9

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

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

Comment 10

[Alexandru Michis [:malexandru]]

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

Comment 11

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 3
• mozilla-beta: 1

Platform and build breakdown:

• windows7-32: 3
  • opt: 3
• windows7-32-shippable: 1
  • opt: 1

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

Comment 12

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows7-32: 1
  • opt: 1

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

Comment 13

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows7-32: 1
  • opt: 1

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

Comment 14

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows7-32: 1
  • opt: 1

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

Comment 15

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

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