1727531 - Intermittent TEST-UNEXPECTED-NOTRUN | /webrtc/RTCPeerConnection-ondatachannel.html | Should be able to send data in a datachannel event handler - expected PASS

Status: RESOLVED INCOMPLETE

(Core :: WebRTC, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2021-08-25T12:16:07.004Z] 12:16:07     INFO - TEST-START | /html/semantics/scripting-1/the-script-element/moving-between-documents/after-prepare-iframe-parse-error-inline-classic.html
[task 2021-08-25T12:16:07.004Z] 12:16:07     INFO - Closing window 793f39ec-3996-437a-be6b-a2af6f85c547
[task 2021-08-25T12:16:07.129Z] 12:16:07     INFO - PID 9176 | [Child 4168: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
[task 2021-08-25T12:16:07.130Z] 12:16:07     INFO - PID 9176 | [Child 4168: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
[task 2021-08-25T12:16:08.115Z] 12:16:08     INFO - 
[task 2021-08-25T12:16:08.115Z] 12:16:08     INFO - TEST-KNOWN-INTERMITTENT-TIMEOUT | /webrtc/RTCPeerConnection-ondatachannel.html | Data channel event should fire when new data channel is announced to the remote peer - Test timed out
[task 2021-08-25T12:16:08.123Z] 12:16:08     INFO - 
[task 2021-08-25T12:16:08.123Z] 12:16:08     INFO - TEST-UNEXPECTED-NOTRUN | /webrtc/RTCPeerConnection-ondatachannel.html | Should be able to send data in a datachannel event handler - expected PASS
[task 2021-08-25T12:16:08.124Z] 12:16:08     INFO - 
[task 2021-08-25T12:16:08.124Z] 12:16:08     INFO - TEST-UNEXPECTED-NOTRUN | /webrtc/RTCPeerConnection-ondatachannel.html | Open event should not be raised when closing the channel in the datachannel event - expected PASS
[task 2021-08-25T12:16:08.125Z] 12:16:08     INFO - 
[task 2021-08-25T12:16:08.125Z] 12:16:08     INFO - TEST-UNEXPECTED-NOTRUN | /webrtc/RTCPeerConnection-ondatachannel.html | Open event should be raised when closing the channel in the datachannel event after enqueuing a task - expected PASS
[task 2021-08-25T12:16:08.126Z] 12:16:08     INFO - 
[task 2021-08-25T12:16:08.126Z] 12:16:08     INFO - TEST-UNEXPECTED-NOTRUN | /webrtc/RTCPeerConnection-ondatachannel.html | Open event should not be raised when sending and immediately closing the channel in the datachannel event - expected PASS
[task 2021-08-25T12:16:08.127Z] 12:16:08     INFO - 
[task 2021-08-25T12:16:08.127Z] 12:16:08     INFO - TEST-UNEXPECTED-NOTRUN | /webrtc/RTCPeerConnection-ondatachannel.html | In-band negotiated channel created on remote peer should match the same configuration as local peer - expected PASS
[task 2021-08-25T12:16:08.128Z] 12:16:08     INFO - 
[task 2021-08-25T12:16:08.128Z] 12:16:08     INFO - TEST-KNOWN-INTERMITTENT-NOTRUN | /webrtc/RTCPeerConnection-ondatachannel.html | In-band negotiated channel created on remote peer should match the same (default) configuration as local peer 
[task 2021-08-25T12:16:08.129Z] 12:16:08     INFO - 
[task 2021-08-25T12:16:08.129Z] 12:16:08     INFO - TEST-KNOWN-INTERMITTENT-NOTRUN | /webrtc/RTCPeerConnection-ondatachannel.html | Negotiated channel should not fire datachannel event on remote peer 
[task 2021-08-25T12:16:08.130Z] 12:16:08     INFO - TEST-KNOWN-INTERMITTENT-TIMEOUT | /webrtc/RTCPeerConnection-ondatachannel.html | took 10225ms
[task 2021-08-25T12:16:08.132Z] 12:16:08     INFO - PID 9176 | 1629893768126	Marionette	INFO	Stopped listening on port 63155
[task 2021-08-25T12:16:08.132Z] 12:16:08     INFO - PID 9176 | [Child 4168: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
[task 2021-08-25T12:16:08.133Z] 12:16:08     INFO - PID 9176 | [Child 4168: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
[task 2021-08-25T12:16:08.138Z] 12:16:08     INFO - PID 9176 | [Child 4168: Main Thread]: D/DataChannel 1ba213faf50: Close()ing 1ba20de9740
[task 2021-08-25T12:16:08.139Z] 12:16:08     INFO - PID 9176 | [Child 4168: Main Thread]: D/DataChannel Connection 1ba20df0000/Channel 1ba20de9740: Closing stream 1
[task 2021-08-25T12:16:08.140Z] 12:16:08     INFO - PID 9176 | [Child 4168: Main Thread]: D/DataChannel Connection 1ba20df0000: Resetting outgoing stream 1
[task 2021-08-25T12:16:08.140Z] 12:16:08     INFO - PID 9176 | [Child 4168: Main Thread]: D/DataChannel Connection 1ba20df0000: Sending outgoing stream reset for 1 streams
[task 2021-08-25T12:16:08.141Z] 12:16:08     INFO - PID 9176 | [Child 4168: Main Thread]: E/DataChannel ***failed: setsockopt RESET, errno 2
[task 2021-08-25T12:16:08.142Z] 12:16:08     INFO - PID 9176 | [Child 4168: Main Thread]: D/DataChannel DataChannelConnection labeled fire-me!(1ba20de9740) (stream 1) changing ready state CONNECTING -> CLOSING
[task 2021-08-25T12:16:08.170Z] 12:16:08     INFO - PID 9176 | (ice/INFO) ICE(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect): peer (PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect:default) Trickle grace period is over; marking every component with only failed pairs as failed.
[task 2021-08-25T12:16:08.174Z] 12:16:08     INFO - PID 9176 | (ice/INFO) ICE-PEER(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect:default)/STREAM(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect transport-id=transport_0 - c9a0c150:f79d367ae4115b1cc5495608c87ff78b)/COMP(1): All pairs are failed, and grace period has elapsed. Marking component as failed.
[task 2021-08-25T12:16:08.175Z] 12:16:08     INFO - PID 9176 | (ice/ERR) ICE(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect)/STREAM(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect transport-id=transport_0 - c9a0c150:f79d367ae4115b1cc5495608c87ff78b): state dump
[task 2021-08-25T12:16:08.176Z] 12:16:08     INFO - PID 9176 | (ice/ERR) ICE(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect)/ICE-STREAM(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect transport-id=transport_0 - c9a0c150:f79d367ae4115b1cc5495608c87ff78b): Local component 1 - dumping candidates
[task 2021-08-25T12:16:08.177Z] 12:16:08     INFO - PID 9176 | (ice/ERR) ICE(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect)/ICE-STREAM(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect transport-id=transport_0 - c9a0c150:f79d367ae4115b1cc5495608c87ff78b)/CAND(kmjA): host(IP4:10.0.0.39:60074/UDP)
[task 2021-08-25T12:16:08.178Z] 12:16:08     INFO - PID 9176 | (ice/ERR) ICE(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect)/ICE-STREAM(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect transport-id=transport_0 - c9a0c150:f79d367ae4115b1cc5495608c87ff78b)/CAND(Pv/8): host(IP4:10.0.0.39:56039/TCP) active
[task 2021-08-25T12:16:08.179Z] 12:16:08     INFO - PID 9176 | (ice/ERR) ICE-PEER(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect:default)/STREAM(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect transport-id=transport_0 - c9a0c150:f79d367ae4115b1cc5495608c87ff78b): state dump
[task 2021-08-25T12:16:08.181Z] 12:16:08     INFO - PID 9176 | (ice/ERR) ICE(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect)/ICE-STREAM(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect transport-id=transport_0 - c9a0c150:f79d367ae4115b1cc5495608c87ff78b): Remote component 1 in state 3 - dumping candidates
[task 2021-08-25T12:16:08.182Z] 12:16:08     INFO - PID 9176 | [Child 4168: Socket Thread]: D/mtransport NrIceCtx(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect): state 0->4
[task 2021-08-25T12:16:08.183Z] 12:16:08     INFO - PID 9176 | [Child 4168: Socket Thread]: D/mtransport NrIceCtx(PC:{436a54dc-9fb6-4c07-893c-fe3849163bda} 1629893758117000 (id=21474836482 url=http://web-platform.test:8000/webrtc/RTCPeerConnect): dumping r_log ringbuffer...
[task 2021-08-25T12:16:08.183Z] 12:16:08     INFO - PID 9176 | [Child 4168: Socket Thread]: D/mtransport (registry/INFO) insert 'ice' (registry) succeeded: ice
[task 2021-08-25T12:16:08.184Z] 12:16:08     INFO - PID 9176 | [Child 4168: Socket Thread]: D/mtransport (registry/INFO) insert 'ice.pref' (registry) succeeded: ice.pref
<...>
[task 2021-08-25T12:16:08.259Z] 12:16:08     INFO - PID 9176 | [Child 4168: Main Thread]: D/DataChannel Deleting DataChannelConnection 1ba20df7c00
[task 2021-08-25T12:16:08.695Z] 12:16:08     INFO - Browser exited with return code 0
[task 2021-08-25T12:16:08.698Z] 12:16:08     INFO - Closing logging queue
[task 2021-08-25T12:16:08.698Z] 12:16:08     INFO - queue closed
[task 2021-08-25T12:16:08.811Z] 12:16:08     INFO - Application command: Z:\task_162989214539623\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_162989214539623\AppData\Local\Temp\tmpitc3q1i6
[task 2021-08-25T12:16:08.818Z] 12:16:08     INFO - Starting runner
[task 2021-08-25T12:16:09.212Z] 12:16:09     INFO - PID 6808 | 1629893769217	Marionette	INFO	Marionette enabled
[task 2021-08-25T12:16:10.790Z] 12:16:10     INFO - PID 6808 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_162989214539623\\AppData\\Local\\Temp\\tmpitc3q1i6\\search.json.mozlz4", (void 0)))
[task 2021-08-25T12:16:11.075Z] 12:16:11     INFO - PID 6808 | 1629893771084	Marionette	INFO	Listening on port 63696
[task 2021-08-25T12:16:11.915Z] 12:16:11     INFO - TEST-START | /webrtc/RTCPeerConnection-onnegotiationneeded.html

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows10-64-2004-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1727531&startday=2021-08-23&endday=2021-08-29&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.