Closed Bug 1667056 Opened 5 years ago Closed 5 years ago

Intermittent dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndRemoteRollbackNoSubsequentRestart.html | Error in test execution: Error: Element _local_{...} should progress currentTime timeout/<@/tests/mochitest/head.js:633:42 ...

Categories

(Core :: WebRTC, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

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


[task 2020-09-24T08:21:53.097Z] 08:21:53 INFO - TEST-START | dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndRemoteRollbackNoSubsequentRestart.html
[task 2020-09-24T08:21:53.122Z] 08:21:53 INFO - GECKO(11060) | [GPU 8980, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:21:53.122Z] 08:21:53 INFO - GECKO(11060) | [GPU 8980, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:21:53.122Z] 08:21:53 INFO - GECKO(11060) | [GPU 8980, Compositor] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:21:53.141Z] 08:21:53 INFO - GECKO(11060) | [GPU 8980, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:21:53.141Z] 08:21:53 INFO - GECKO(11060) | [GPU 8980, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:21:53.141Z] 08:21:53 INFO - GECKO(11060) | [GPU 8980, Compositor] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:21:53.220Z] 08:21:53 INFO - GECKO(11060) | [GPU 8980, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:21:53.220Z] 08:21:53 INFO - GECKO(11060) | [GPU 8980, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:21:53.221Z] 08:21:53 INFO - GECKO(11060) | [GPU 8980, Compositor] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:21:53.261Z] 08:21:53 INFO - GECKO(11060) | TEST DEVICES: No test device found in media.audio_loopback_dev, using fake audio streams.
[task 2020-09-24T08:21:53.261Z] 08:21:53 INFO - GECKO(11060) | TEST DEVICES: No test device found in media.video_loopback_dev, using fake video streams.
[task 2020-09-24T08:21:53.340Z] 08:21:53 INFO - GECKO(11060) | Timecard created 1600935711.156000
[task 2020-09-24T08:21:53.340Z] 08:21:53 INFO - GECKO(11060) | Timestamp | Delta | Event | File | Function
[task 2020-09-24T08:21:53.341Z] 08:21:53 INFO - GECKO(11060) | ======================================================================================================================
[task 2020-09-24T08:21:53.341Z] 08:21:53 INFO - GECKO(11060) | 0.000000 | 0.000000 | Constructor Completed | PeerConnectionImpl.cpp:326 | PeerConnectionImpl
[task 2020-09-24T08:21:53.341Z] 08:21:53 INFO - GECKO(11060) | 0.001000 | 0.001000 | Initializing PC Ctx | PeerConnectionImpl.cpp:455 | Initialize
[task 2020-09-24T08:21:53.342Z] 08:21:53 INFO - GECKO(11060) | 0.143000 | 0.142000 | Create Offer | PeerConnectionImpl.cpp:1217 | CreateOffer
[task 2020-09-24T08:21:53.342Z] 08:21:53 INFO - GECKO(11060) | 0.152000 | 0.009000 | Set Local Description | PeerConnectionImpl.cpp:1286 | SetLocalDescription
[task 2020-09-24T08:21:53.342Z] 08:21:53 INFO - GECKO(11060) | 0.161000 | 0.009000 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2528 | IceGatheringStateChange
[task 2020-09-24T08:21:53.342Z] 08:21:53 INFO - GECKO(11060) | 0.203000 | 0.042000 | Ice gathering state: complete | PeerConnectionImpl.cpp:2531 | IceGatheringStateChange
[task 2020-09-24T08:21:53.343Z] 08:21:53 INFO - GECKO(11060) | 0.222000 | 0.019000 | Set Remote Description | PeerConnectionImpl.cpp:1386 | SetRemoteDescription
[task 2020-09-24T08:21:53.343Z] 08:21:53 INFO - GECKO(11060) | 0.262000 | 0.040000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.344Z] 08:21:53 INFO - GECKO(11060) | 0.278000 | 0.016000 | Look up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.344Z] 08:21:53 INFO - GECKO(11060) | 0.278000 | 0.000000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.344Z] 08:21:53 INFO - GECKO(11060) | 0.279000 | 0.001000 | Look up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.344Z] 08:21:53 INFO - GECKO(11060) | 0.280000 | 0.001000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.344Z] 08:21:53 INFO - GECKO(11060) | 0.284000 | 0.004000 | Done looking up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.345Z] 08:21:53 INFO - GECKO(11060) | 0.284000 | 0.000000 | Done looking up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.347Z] 08:21:53 INFO - GECKO(11060) | 0.285000 | 0.001000 | Ice state: checking | PeerConnectionImpl.cpp:2472 | IceConnectionStateChange
[task 2020-09-24T08:21:53.347Z] 08:21:53 INFO - GECKO(11060) | 0.331000 | 0.046000 | Ice state: connected | PeerConnectionImpl.cpp:2475 | IceConnectionStateChange
[task 2020-09-24T08:21:53.347Z] 08:21:53 INFO - GECKO(11060) | 1.071000 | 0.740000 | Create Offer | PeerConnectionImpl.cpp:1217 | CreateOffer
[task 2020-09-24T08:21:53.347Z] 08:21:53 INFO - GECKO(11060) | 1.073000 | 0.002000 | Set Local Description | PeerConnectionImpl.cpp:1286 | SetLocalDescription
[task 2020-09-24T08:21:53.347Z] 08:21:53 INFO - GECKO(11060) | 1.105000 | 0.032000 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2528 | IceGatheringStateChange
[task 2020-09-24T08:21:53.347Z] 08:21:53 INFO - GECKO(11060) | 1.125000 | 0.020000 | Ice gathering state: complete | PeerConnectionImpl.cpp:2531 | IceGatheringStateChange
[task 2020-09-24T08:21:53.347Z] 08:21:53 INFO - GECKO(11060) | 1.132000 | 0.007000 | Set Local Description | PeerConnectionImpl.cpp:1286 | SetLocalDescription
[task 2020-09-24T08:21:53.349Z] 08:21:53 INFO - GECKO(11060) | 1.141000 | 0.009000 | Create Offer | PeerConnectionImpl.cpp:1217 | CreateOffer
[task 2020-09-24T08:21:53.359Z] 08:21:53 INFO - GECKO(11060) | 1.145000 | 0.004000 | Set Local Description | PeerConnectionImpl.cpp:1286 | SetLocalDescription
[task 2020-09-24T08:21:53.359Z] 08:21:53 INFO - GECKO(11060) | 1.182000 | 0.037000 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2528 | IceGatheringStateChange
[task 2020-09-24T08:21:53.361Z] 08:21:53 INFO - GECKO(11060) | 1.214000 | 0.032000 | Ice gathering state: complete | PeerConnectionImpl.cpp:2531 | IceGatheringStateChange
[task 2020-09-24T08:21:53.361Z] 08:21:53 INFO - GECKO(11060) | 1.222000 | 0.008000 | Set Remote Description | PeerConnectionImpl.cpp:1386 | SetRemoteDescription
[task 2020-09-24T08:21:53.366Z] 08:21:53 INFO - GECKO(11060) | 1.263000 | 0.041000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.366Z] 08:21:53 INFO - GECKO(11060) | 1.277000 | 0.014000 | Look up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.366Z] 08:21:53 INFO - GECKO(11060) | 1.277000 | 0.000000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.368Z] 08:21:53 INFO - GECKO(11060) | 1.281000 | 0.004000 | Look up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.368Z] 08:21:53 INFO - GECKO(11060) | 1.281000 | 0.000000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.370Z] 08:21:53 INFO - GECKO(11060) | 1.282000 | 0.001000 | Done looking up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.374Z] 08:21:53 INFO - GECKO(11060) | 1.282000 | 0.000000 | Done looking up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.374Z] 08:21:53 INFO - GECKO(11060) | 1.291000 | 0.009000 | Ice state: checking | PeerConnectionImpl.cpp:2472 | IceConnectionStateChange
[task 2020-09-24T08:21:53.374Z] 08:21:53 INFO - GECKO(11060) | 1.335000 | 0.044000 | Ice state: connected | PeerConnectionImpl.cpp:2475 | IceConnectionStateChange
[task 2020-09-24T08:21:53.375Z] 08:21:53 INFO - GECKO(11060) | 2.179000 | 0.844000 | Destructor Invoked | PeerConnectionImpl.cpp:335 | ~PeerConnectionImpl
[task 2020-09-24T08:21:53.375Z] 08:21:53 INFO - GECKO(11060) | [Child 8328: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:360: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for f762b401d659fb6a
[task 2020-09-24T08:21:53.375Z] 08:21:53 INFO - GECKO(11060) | Timecard created 1600935711.160000
[task 2020-09-24T08:21:53.380Z] 08:21:53 INFO - GECKO(11060) | Timestamp | Delta | Event | File | Function
[task 2020-09-24T08:21:53.380Z] 08:21:53 INFO - GECKO(11060) | ======================================================================================================================
[task 2020-09-24T08:21:53.380Z] 08:21:53 INFO - GECKO(11060) | 0.000000 | 0.000000 | Constructor Completed | PeerConnectionImpl.cpp:326 | PeerConnectionImpl
[task 2020-09-24T08:21:53.382Z] 08:21:53 INFO - GECKO(11060) | 0.001000 | 0.001000 | Initializing PC Ctx | PeerConnectionImpl.cpp:455 | Initialize
[task 2020-09-24T08:21:53.384Z] 08:21:53 INFO - GECKO(11060) | 0.153000 | 0.152000 | Set Remote Description | PeerConnectionImpl.cpp:1386 | SetRemoteDescription
[task 2020-09-24T08:21:53.384Z] 08:21:53 INFO - GECKO(11060) | 0.185000 | 0.032000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.386Z] 08:21:53 INFO - GECKO(11060) | 0.202000 | 0.017000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.386Z] 08:21:53 INFO - GECKO(11060) | 0.208000 | 0.006000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.386Z] 08:21:53 INFO - GECKO(11060) | 0.209000 | 0.001000 | Create Answer | PeerConnectionImpl.cpp:1248 | CreateAnswer
[task 2020-09-24T08:21:53.388Z] 08:21:53 INFO - GECKO(11060) | 0.210000 | 0.001000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.390Z] 08:21:53 INFO - GECKO(11060) | 0.211000 | 0.001000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.390Z] 08:21:53 INFO - GECKO(11060) | 0.212000 | 0.001000 | Set Local Description | PeerConnectionImpl.cpp:1286 | SetLocalDescription
[task 2020-09-24T08:21:53.390Z] 08:21:53 INFO - GECKO(11060) | 0.222000 | 0.010000 | Look up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.392Z] 08:21:53 INFO - GECKO(11060) | 0.222000 | 0.000000 | Look up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.392Z] 08:21:53 INFO - GECKO(11060) | 0.222000 | 0.000000 | Look up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.394Z] 08:21:53 INFO - GECKO(11060) | 0.222000 | 0.000000 | Look up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.394Z] 08:21:53 INFO - GECKO(11060) | 0.222000 | 0.000000 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2528 | IceGatheringStateChange
[task 2020-09-24T08:21:53.394Z] 08:21:53 INFO - GECKO(11060) | 0.260000 | 0.038000 | Done looking up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.396Z] 08:21:53 INFO - GECKO(11060) | 0.260000 | 0.000000 | Done looking up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.396Z] 08:21:53 INFO - GECKO(11060) | 0.260000 | 0.000000 | Done looking up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.396Z] 08:21:53 INFO - GECKO(11060) | 0.260000 | 0.000000 | Done looking up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.396Z] 08:21:53 INFO - GECKO(11060) | 0.262000 | 0.002000 | Ice gathering state: complete | PeerConnectionImpl.cpp:2531 | IceGatheringStateChange
[task 2020-09-24T08:21:53.398Z] 08:21:53 INFO - GECKO(11060) | 0.275000 | 0.013000 | Ice state: checking | PeerConnectionImpl.cpp:2472 | IceConnectionStateChange
[task 2020-09-24T08:21:53.398Z] 08:21:53 INFO - GECKO(11060) | 0.330000 | 0.055000 | Ice state: connected | PeerConnectionImpl.cpp:2475 | IceConnectionStateChange
[task 2020-09-24T08:21:53.398Z] 08:21:53 INFO - GECKO(11060) | 1.072000 | 0.742000 | Set Remote Description | PeerConnectionImpl.cpp:1386 | SetRemoteDescription
[task 2020-09-24T08:21:53.398Z] 08:21:53 INFO - GECKO(11060) | 1.100000 | 0.028000 | Create Answer | PeerConnectionImpl.cpp:1248 | CreateAnswer
[task 2020-09-24T08:21:53.398Z] 08:21:53 INFO - GECKO(11060) | 1.112000 | 0.012000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.403Z] 08:21:53 INFO - GECKO(11060) | 1.120000 | 0.008000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.403Z] 08:21:53 INFO - GECKO(11060) | 1.123000 | 0.003000 | Set Remote Description | PeerConnectionImpl.cpp:1386 | SetRemoteDescription
[task 2020-09-24T08:21:53.403Z] 08:21:53 INFO - GECKO(11060) | 1.129000 | 0.006000 | Look up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.403Z] 08:21:53 INFO - GECKO(11060) | 1.129000 | 0.000000 | Look up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.405Z] 08:21:53 INFO - GECKO(11060) | 1.129000 | 0.000000 | Look up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.405Z] 08:21:53 INFO - GECKO(11060) | 1.129000 | 0.000000 | Look up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.407Z] 08:21:53 INFO - GECKO(11060) | 1.138000 | 0.009000 | Done looking up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.407Z] 08:21:53 INFO - GECKO(11060) | 1.139000 | 0.001000 | Done looking up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.407Z] 08:21:53 INFO - GECKO(11060) | 1.139000 | 0.000000 | Done looking up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.407Z] 08:21:53 INFO - GECKO(11060) | 1.139000 | 0.000000 | Done looking up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.407Z] 08:21:53 INFO - GECKO(11060) | 1.147000 | 0.008000 | Set Remote Description | PeerConnectionImpl.cpp:1386 | SetRemoteDescription
[task 2020-09-24T08:21:53.412Z] 08:21:53 INFO - GECKO(11060) | 1.178000 | 0.031000 | Create Answer | PeerConnectionImpl.cpp:1248 | CreateAnswer
[task 2020-09-24T08:21:53.412Z] 08:21:53 INFO - GECKO(11060) | 1.198000 | 0.020000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.412Z] 08:21:53 INFO - GECKO(11060) | 1.207000 | 0.009000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.412Z] 08:21:53 INFO - GECKO(11060) | 1.211000 | 0.004000 | Set Local Description | PeerConnectionImpl.cpp:1286 | SetLocalDescription
[task 2020-09-24T08:21:53.412Z] 08:21:53 INFO - GECKO(11060) | 1.214000 | 0.003000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.412Z] 08:21:53 INFO - GECKO(11060) | 1.221000 | 0.007000 | Look up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.412Z] 08:21:53 INFO - GECKO(11060) | 1.221000 | 0.000000 | Look up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.413Z] 08:21:53 INFO - GECKO(11060) | 1.222000 | 0.001000 | Ice gathering state: gathering | PeerConnectionImpl.cpp:2528 | IceGatheringStateChange
[task 2020-09-24T08:21:53.413Z] 08:21:53 INFO - GECKO(11060) | 1.222000 | 0.000000 | Look up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.413Z] 08:21:53 INFO - GECKO(11060) | 1.223000 | 0.001000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.413Z] 08:21:53 INFO - GECKO(11060) | 1.254000 | 0.031000 | Look up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.417Z] 08:21:53 INFO - GECKO(11060) | 1.255000 | 0.001000 | Add Ice Candidate | PeerConnectionImpl.cpp:1534 | AddIceCandidate
[task 2020-09-24T08:21:53.417Z] 08:21:53 INFO - GECKO(11060) | 1.259000 | 0.004000 | Done looking up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.417Z] 08:21:53 INFO - GECKO(11060) | 1.259000 | 0.000000 | Done looking up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.417Z] 08:21:53 INFO - GECKO(11060) | 1.259000 | 0.000000 | Done looking up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.417Z] 08:21:53 INFO - GECKO(11060) | 1.259000 | 0.000000 | Done looking up mDNS name | PeerConnectionImpl.cpp:1822 | StampTimecard
[task 2020-09-24T08:21:53.417Z] 08:21:53 INFO - GECKO(11060) | 1.268000 | 0.009000 | Ice gathering state: complete | PeerConnectionImpl.cpp:2531 | IceGatheringStateChange
[task 2020-09-24T08:21:53.417Z] 08:21:53 INFO - GECKO(11060) | 1.279000 | 0.011000 | Ice state: checking | PeerConnectionImpl.cpp:2472 | IceConnectionStateChange
[task 2020-09-24T08:21:53.417Z] 08:21:53 INFO - GECKO(11060) | 1.333000 | 0.054000 | Ice state: connected | PeerConnectionImpl.cpp:2475 | IceConnectionStateChange
[task 2020-09-24T08:21:53.417Z] 08:21:53 INFO - GECKO(11060) | 2.188000 | 0.855000 | Destructor Invoked | PeerConnectionImpl.cpp:335 | ~PeerConnectionImpl
[task 2020-09-24T08:21:53.418Z] 08:21:53 INFO - GECKO(11060) | [Child 8328: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:360: ~PeerConnectionImpl: PeerConnectionImpl destructor invoked for f1ed55e61890a203
[task 2020-09-24T08:21:53.496Z] 08:21:53 INFO - GECKO(11060) | [GPU 8980, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:21:53.496Z] 08:21:53 INFO - GECKO(11060) | [GPU 8980, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:21:53.496Z] 08:21:53 INFO - GECKO(11060) | [GPU 8980, Compositor] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:21:53.667Z] 08:21:53 INFO - GECKO(11060) | [Child 8328: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:325: PeerConnectionImpl: PeerConnectionImpl constructor for
[task 2020-09-24T08:21:53.668Z] 08:21:53 INFO - GECKO(11060) | [Parent 7864: Socket Thread]: D/mtransport NrIceCtx static call to find local stun addresses
[task 2020-09-24T08:21:53.668Z] 08:21:53 INFO - GECKO(11060) | [Child 8328: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:325: PeerConnectionImpl: PeerConnectionImpl constructor for
[task 2020-09-24T08:21:53.678Z] 08:21:53 INFO - GECKO(11060) | [Parent 7864: Socket Thread]: D/mtransport NrIceCtx static call to find local stun addresses
[task 2020-09-24T08:21:53.688Z] 08:21:53 INFO - GECKO(11060) | TEST DEVICES: No test device found in media.audio_loopback_dev, using fake audio streams.
[task 2020-09-24T08:21:53.688Z] 08:21:53 INFO - GECKO(11060) | TEST DEVICES: No test device found in media.video_loopback_dev, using fake video streams.
[task 2020-09-24T08:21:53.690Z] 08:21:53 INFO - GECKO(11060) | [Child 8328: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:74: OnStunAddrsAvailable: receiving (4) stun addrs
[task 2020-09-24T08:21:53.690Z] 08:21:53 INFO - GECKO(11060) | [Child 8328: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:74: OnStunAddrsAvailable: receiving (4) stun addrs
[task 2020-09-24T08:21:53.761Z] 08:21:53 INFO - GECKO(11060) | TEST DEVICES: No test device found in media.audio_loopback_dev, using fake audio streams.
[task 2020-09-24T08:21:53.761Z] 08:21:53 INFO - GECKO(11060) | TEST DEVICES: No test device found in media.video_loopback_dev, using fake video streams.
[task 2020-09-24T08:21:53.820Z] 08:21:53 INFO - GECKO(11060) | [Child 8328: Main Thread]: I/signaling [main|sdp_config] sdp_config.c:86: SDP: Initialized config pointer: 000001D0B6EDDF20
[task 2020-09-24T08:21:53.820Z] 08:21:53 INFO - GECKO(11060) | [Child 8328: Main Thread]: I/jsep [1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR]: stable -> have-local-offer
[task 2020-09-24T08:21:53.821Z] 08:21:53 INFO - GECKO(11060) | (ice/WARNING) /builds/worker/checkouts/gecko/dom/media/webrtc/transport/third_party/nICEr/src/net/nr_socket_multi_tcp.c:617 function nr_socket_multi_tcp_listen failed with error 3
[task 2020-09-24T08:21:53.821Z] 08:21:53 INFO - GECKO(11060) | (ice/WARNING) ICE(PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochit
[task 2020-09-24T08:21:53.821Z] 08:21:53 INFO - GECKO(11060) | est/test_peerConnection_restartIceLocalAndR): failed to cr
[task 2020-09-24T08:21:53.821Z] 08:21:53 INFO - GECKO(11060) | eate passive TCP host candidate: 3
[task 2020-09-24T08:21:53.822Z] 08:21:53 INFO - GECKO(11060) | (ice/WARNING) /builds/worker/checkouts/gecko/dom/media/webrtc/transport/third_party/nICEr/src/net/nr_socket_multi_tcp.c:617
[task 2020-09-24T08:21:53.822Z] 08:21:53 INFO - GECKO(11060) | function nr_socket_multi_tcp_listen failed with error 3
[task 2020-09-24T08:21:53.822Z] 08:21:53 INFO - GECKO(11060) | (ice/WARNING) ICE(PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tes
[task 2020-09-24T08:21:53.822Z] 08:21:53 INFO - GECKO(11060) | ts/mochitest/test_peerConnection_restartIceLocalAndR): failed to create passive TCP host candidate: 3
[task 2020-09-24T08:21:53.823Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport NrIceCtx(PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR): trickling candidate candidate:0 1 UDP 2122252543 a637c568-5ab2-4d62-bdbb-f1d56e495cc0.local 52347 typ host
[task 2020-09-24T08:21:53.823Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport Couldn't get default ICE candidate for 'PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR transport-id=transport_0', no candidates.
[task 2020-09-24T08:21:53.823Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport NrIceCtx(PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR): trickling candidate candidate:1 1 TCP 2105524479 a637c568-5ab2-4d62-bdbb-f1d56e495cc0.local 9 typ host tcptype active
[task 2020-09-24T08:21:53.823Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport Couldn't get default ICE candidate for 'PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR transport-id=transport_0', no candidates.
[task 2020-09-24T08:21:53.823Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport NrIceCtx(PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR): trickling candidate candidate:0 2 UDP 2122252542 a637c568-5ab2-4d62-bdbb-f1d56e495cc0.local 52348 typ host
[task 2020-09-24T08:21:53.823Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport NrIceCtx(PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR): trickling candidate candidate:1 2 TCP 2105524478 a637c568-5ab2-4d62-bdbb-f1d56e495cc0.local 9 typ host tcptype active
[task 2020-09-24T08:21:53.823Z] 08:21:53 INFO - GECKO(11060) | (ice/INFO) ICE(PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR): All candidates initializ[Child 8328: Main Thread]: I/signaling [main|sdp_config] sdp_config.c:86: SDP: Initialized config pointer: 000001D0B762D740
[task 2020-09-24T08:21:53.823Z] 08:21:53 INFO - GECKO(11060) | ed
[task 2020-09-24T08:21:53.824Z] 08:21:53 INFO - GECKO(11060) | [Child 8328: Main Thread]: I/jsep [1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR]: stable -> have-remote-offer
[task 2020-09-24T08:21:53.874Z] 08:21:53 INFO - GECKO(11060) | [Child 8328: Main Thread]: I/signaling [main|sdp_config] sdp_config.c:86: SDP: Initialized config pointer: 000001D0B762F4A0
[task 2020-09-24T08:21:53.874Z] 08:21:53 INFO - GECKO(11060) | [Child 8328: Main Thread]: I/jsep [1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR]: have-remote-offer -> stable
[task 2020-09-24T08:21:53.874Z] 08:21:53 INFO - GECKO(11060) | [Child 8328: Main Thread]: I/signaling [main|WebrtcAudioSessionConduit] AudioConduit.cpp:255: SetDtmfPayloadType : setting dtmf payload 101
[task 2020-09-24T08:21:53.874Z] 08:21:53 INFO - GECKO(11060) | (ice/WARNING) /builds/worker/checkouts/gecko/dom/media/webrtc/transport/third_party/nICEr/src/net/nr_socket_multi_tcp.c:617 function nr_socket_multi_tcp_listen failed with error 3
[task 2020-09-24T08:21:53.875Z] 08:21:53 INFO - GECKO(11060) | (ice/WARNING) ICE(PC:1600935713667000 (id=2147484134 url=https://example.com/t
[task 2020-09-24T08:21:53.875Z] 08:21:53 INFO - GECKO(11060) | ests/dom/media/tests/mochitest/test_peerConnection_restar
[task 2020-09-24T08:21:53.875Z] 08:21:53 INFO - GECKO(11060) | tIceLocalAndR): failed to create passive TCP host candidate: 3
[task 2020-09-24T08:21:53.877Z] 08:21:53 INFO - GECKO(11060) | (ice/WARNING) ICE(PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR): peer
[task 2020-09-24T08:21:53.877Z] 08:21:53 INFO - GECKO(11060) | (PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_pe
[task 2020-09-24T08:21:53.878Z] 08:21:53 INFO - GECKO(11060) | erConnection_restartIceLocalAndR:default) has no stream matching stream PC:1
[task 2020-09-24T08:21:53.878Z] 08:21:53 INFO - GECKO(11060) | 600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR transport-id=tr
[task 2020-09-24T08:21:53.878Z] 08:21:53 INFO - GECKO(11060) | ansport_0 - a3508f8e:438b7ae[Child 8328: Main Thread]: I/signaling [main|sdp_config] sdp_config.c:86: SDP: Initialized config pointer: 000001D0B7678970
[task 2020-09-24T08:21:53.879Z] 08:21:53 INFO - GECKO(11060) | ace9baf15e5bc1f4eeda3d621
[task 2020-09-24T08:21:53.879Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport Setting up DTLS as client
[task 2020-09-24T08:21:53.881Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport Setting DTLS1.3 supported_versions workaround
[task 2020-09-24T08:21:53.881Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: E/mtransport Couldn't disable 'PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR transport-id=transport_0':2
[task 2020-09-24T08:21:53.881Z] 08:21:53 INFO - GECKO(11060) | (ice/NOTICE) ICE(PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR): peer (PC:160093571366[Child 8328: Main Thread]: I/jsep [1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR]: have-local-offer -> stable
[task 2020-09-24T08:21:53.881Z] 08:21:53 INFO - GECKO(11060) | 7000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR:default) no streams with non-empty check lists
[task 2020-09-24T08:21:53.883Z] 08:21:53 INFO - GECKO(11060) | (ice/NOTICE) ICE(PC:1600935713667000 (id=2147[Child 8328: Main Thread]: I/signaling [main|WebrtcAudioSessionConduit] AudioConduit.cpp:255: SetDtmfPayloadType : setting dtmf payload 101
[task 2020-09-24T08:21:53.883Z] 08:21:53 INFO - GECKO(11060) | 484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR): peer (PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR:default) no streams with pre-answer requests
[task 2020-09-24T08:21:53.884Z] 08:21:53 INFO - GECKO(11060) | (ice/NOTICE) ICE(PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartI
[task 2020-09-24T08:21:53.884Z] 08:21:53 INFO - GECKO(11060) | ceLocalAndR): peer (PC:160093571366
[task 2020-09-24T08:21:53.885Z] 08:21:53 INFO - GECKO(11060) | 7000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR:default) no checks to start
[task 2020-09-24T08:21:53.885Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport Couldn't start peer checks on PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR, assuming trickle ICE
[task 2020-09-24T08:21:53.885Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport NrIceCtx(PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR): trickling candidate candidate:0 1 UDP 2122252543 adb76a6d-5307-4f96-9122-f304b34480c2.local 52350 typ host
[task 2020-09-24T08:21:53.886Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport Couldn't get default ICE candidate for 'PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR transport-id=transport_0', no candidates.
[task 2020-09-24T08:21:53.886Z] 08:21:53 INFO - GECKO(11060) | (ice/ERR) ICE(PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLo
[task 2020-09-24T08:21:53.886Z] 08:21:53 INFO - GECKO(11060) | calAndR): peer (PC:1600935713667000 (id=2147484134 url=h
[task 2020-09-24T08:21:53.888Z] 08:21:53 INFO - GECKO(11060) | ttps://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLoc
[task 2020-09-24T08:21:53.888Z] 08:21:53 INFO - GECKO(11060) | alAndR:default) pairing local trickle ICE candidate host(IP4:10.145.58.106:52350/UDP)
[task 2020-09-24T08:21:53.888Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport NrIceCtx(PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR): trickling candidate candidate:1 1 TCP 2105524479 adb76a6d-5307-4f96-9122-f304b34480c2.local 9 typ host tcptype active
[task 2020-09-24T08:21:53.890Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport Couldn't get default ICE candidate for 'PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR transport-id=transport_0', no candidates.
[task 2020-09-24T08:21:53.890Z] 08:21:53 INFO - GECKO(11060) | (ice/ERR) ICE(PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/t
[task 2020-09-24T08:21:53.891Z] 08:21:53 INFO - GECKO(11060) | est_peerConnection_resta
[task 2020-09-24T08:21:53.891Z] 08:21:53 INFO - GECKO(11060) | rtIceLocalAndR): peer (PC:160
[task 2020-09-24T08:21:53.891Z] 08:21:53 INFO - GECKO(11060) | 0935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR:default) pairing local trickle ICE candidate host(IP4:10.145.58.106:64401/TCP) active
[task 2020-09-24T08:21:53.892Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport Couldn't get default ICE candidate for 'PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR transport-id=transport_0', no candidates.
[task 2020-09-24T08:21:53.892Z] 08:21:53 INFO - GECKO(11060) | (ice/INFO) ICE(PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR): All candidates initialized
[task 2020-09-24T08:21:53.892Z] 08:21:53 INFO - GECKO(11060) | (ice/WARNING) ICE(PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR): peer (PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR:default) has no stream matching stream PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR transport-id=transport_0 - f2a0ae76:9919f1036afb6607cdca4ed263a7e0d1
[task 2020-09-24T08:21:53.892Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport Setting up DTLS as server
[task 2020-09-24T08:21:53.894Z] 08:21:53 INFO - GECKO(11060) | (ice/NOTICE) ICE(PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR): peer (PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR:default) no streams with non-empty check lists
[task 2020-09-24T08:21:53.896Z] 08:21:53 INFO - GECKO(11060) | (ice/NOTICE) ICE(PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR): peer (PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR:default) no streams with pre-answer requests
[task 2020-09-24T08:21:53.896Z] 08:21:53 INFO - GECKO(11060) | (ice/NOTICE) ICE(PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR): peer (PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR:default) no checks to start
[task 2020-09-24T08:21:53.896Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport Couldn't start peer checks on PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR, assuming trickle ICE
[task 2020-09-24T08:21:53.918Z] 08:21:53 INFO - GECKO(11060) | [Socket 7376: Socket Thread]: D/mtransport NrIceCtx(PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR)/STREAM(PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR transport-id=transport_0) : parsing trickle candidate candidate:0 1 UDP 2122252543 10.145.58.106 52347 typ host
[task 2020-09-24T08:21:53.920Z] 08:21:53 INFO - GECKO(11060) | (ice/INFO) ICE-PEER(PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR:default)/CAND-PAIR(6prc): setting pair to state FROZEN: 6prc|IP4:10.145.58.106:52350/UDP|IP4:10.145.58.106:52347/UDP(host(IP4:10.145.58.106:52350/UDP)|candidate:0 1 UDP 2122252543 10.145.58.
[task 2020-09-24T08:21:53.920Z] 08:21:53 INFO - GECKO(11060) | 106 52347 typ host)
[task 2020-09-24T08:21:53.920Z] 08:21:53 INFO - GECKO(11060) | (ice/INFO) ICE(PC:1600935713667000 (id=2147484134 url=http
[task 2020-09-24T08:21:53.920Z] 08:21:53 INFO - GECKO(11060) | s://example.com/tests/dom/media/tests/mochite
[task 2020-09-24T08:21:53.921Z] 08:21:53 INFO - GECKO(11060) | st/test_peerConnection_restartIceLocalAndR)/CAND-PAIR(6
[task 2020-09-24T08:21:53.921Z] 08:21:53 INFO - GECKO(11060) | prc): Pairing candidate IP4:10.145.58.106:52350/UDP (7e7f00ff):IP4:10.145.58.106:5
[task 2020-09-24T08:21:53.921Z] 08:21:53 INFO - GECKO(11060) | 2347/UDP (7e7f00ff) priority=9115005270282338815 (7e7f00fffcfe01ff)
[task 2020-09-24T08:21:53.923Z] 08:21:53 INFO - GECKO(11060) | (ice/INFO) ICE-PEER(PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/moc
[task 2020-09-24T08:21:53.923Z] 08:21:53 INFO - GECKO(11060) | hitest/test_peerConnection_restartIceLocalAndR:default)/ICE-STREAM(PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR transport-id=transport_0 - a3508f8e:438b7aeace9baf15e5bc1f4eeda3d621): Starting check timer for stream.
[task 2020-09-24T08:21:53.924Z] 08:21:53 INFO - GECKO(11060) | (ice/INFO) ICE-PEER(PC:1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_
[task 2020-09-24T08:21:53.924Z] 08:21:53 INFO - GECKO(11060) | restartIceLocalAndR:default)/CAND-PAIR(
[task 2020-09-24T08:21:53.924Z] 08:21:53 INFO - GECKO(11060) | 6prc): setting pair to state WAITING: 6prc|IP4:10.14
[task 2020-09-24T08:21:53.924Z] 08:21:53 INFO - GECKO(11060) | 5.58.106:52350/UDP|IP4:10.145.58.106:52
<...>
[task 2020-09-24T08:22:54.640Z] 08:22:54 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndRemoteRollbackNoSubsequentRestart.html | RTP flowing for audio track {ace46e0f-c8f5-4533-b6f5-4ef69bccb984}
[task 2020-09-24T08:22:54.641Z] 08:22:54 INFO - Checking for stats in [["60515ae1",{"id":"60515ae1","timestamp":1600935714522,"type":"candidate-pair","bytesReceived":9147,"bytesSent":9093,"lastPacketReceivedTimestamp":360507426417,"lastPacketSentTimestamp":360507426417,"localCandidateId":"32cf29ac","nominated":true,"priority":9115005270282338000,"readable":true,"remoteCandidateId":"5f1d5825","selected":true,"state":"succeeded","transportId":"transport_0","writable":true}],["32cf29ac",{"id":"32cf29ac","timestamp":1600935714522,"type":"local-candidate","address":"adb76a6d-5307-4f96-9122-f304b34480c2.local","candidateType":"host","port":52350,"priority":2122252543,"protocol":"udp"}],["bfd57a23",{"id":"bfd57a23","timestamp":1600935714522,"type":"local-candidate","address":"adb76a6d-5307-4f96-9122-f304b34480c2.local","candidateType":"host","port":64401,"priority":2105524479,"protocol":"tcp"}],["5f1d5825",{"id":"5f1d5825","timestamp":1600935714522,"type":"remote-candidate","address":"a637c568-5ab2-4d62-bdbb-f1d56e495cc0.local","candidateType":"host","port":52347,"priority":2122252543,"protocol":"udp"}],["d92fda3a",{"id":"d92fda3a","timestamp":1600935714522,"type":"remote-candidate","address":"a637c568-5ab2-4d62-bdbb-f1d56e495cc0.local","candidateType":"host","port":9,"priority":2105524479,"protocol":"tcp"}],["eb8453fe",{"id":"eb8453fe","timestamp":1600935714522,"type":"outbound-rtp","kind":"audio","mediaType":"audio","ssrc":76088613,"bytesSent":7581,"packetsSent":41,"nackCount":0}]] for audio track {7d71deb5-0f42-4f02-b933-a342522fe142}retry number 0
[task 2020-09-24T08:22:54.641Z] 08:22:54 INFO - Should have RTP stats for track {7d71deb5-0f42-4f02-b933-a342522fe142}
[task 2020-09-24T08:22:54.641Z] 08:22:54 INFO - RTP stats: {"id":"eb8453fe","timestamp":1600935714522,"type":"outbound-rtp","kind":"audio","mediaType":"audio","ssrc":76088613,"bytesSent":7581,"packetsSent":41,"nackCount":0}
[task 2020-09-24T08:22:54.641Z] 08:22:54 INFO - Track {7d71deb5-0f42-4f02-b933-a342522fe142} has 41 outbound-rtp RTP packets.
[task 2020-09-24T08:22:54.642Z] 08:22:54 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndRemoteRollbackNoSubsequentRestart.html | RTP flowing for audio track {7d71deb5-0f42-4f02-b933-a342522fe142}
[task 2020-09-24T08:22:54.642Z] 08:22:54 INFO - Buffered messages finished
[task 2020-09-24T08:22:54.642Z] 08:22:54 INFO - TEST-UNEXPECTED-FAIL | dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndRemoteRollbackNoSubsequentRestart.html | Error in test execution: Error: Element local{7d71deb5-0f42-4f02-b933-a342522fe142} should progress currentTime timeout/<@https://example.com/tests/dom/media/tests/mochitest/head.js:633:42 ...
[task 2020-09-24T08:22:54.642Z] 08:22:54 INFO - SimpleTest.ok@https://example.com/tests/SimpleTest/SimpleTest.js:417:16
[task 2020-09-24T08:22:54.642Z] 08:22:54 INFO - execute/<@https://example.com/tests/dom/media/tests/mochitest/head.js:929:11
[task 2020-09-24T08:22:54.643Z] 08:22:54 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndRemoteRollbackNoSubsequentRestart.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2020-09-24T08:22:54.643Z] 08:22:54 INFO - GECKO(11060) | (stun/INFO) STUN-CLIENT(consent): Received response; processing
[task 2020-09-24T08:22:54.644Z] 08:22:54 INFO - GECKO(11060) | (ice/INFO) ICE(PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR)/STREAM
[task 2020-09-24T08:22:54.644Z] 08:22:54 INFO - Closing peer connections
[task 2020-09-24T08:22:54.644Z] 08:22:54 INFO - GECKO(11060) | (PC:1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR transport-id=transport_0 - f2a0ae76:9919f1036afb6607cdca4ed263a7e0d1)/COMP(1): Consent refreshed
[task 2020-09-24T08:22:54.644Z] 08:22:54 INFO - Waiting for track {44308787-35ba-4687-9a95-a2e95437d95e} (audio) to end.
[task 2020-09-24T08:22:54.644Z] 08:22:54 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndRemoteRollbackNoSubsequentRestart.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2020-09-24T08:22:54.645Z] 08:22:54 INFO - GECKO(11060) | [Child 8328: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2100: CloseInt: Closing PeerConnectionImpl 7abf565fc0c49e36; ending call
[task 2020-09-24T08:22:54.645Z] 08:22:54 INFO - GECKO(11060) | [Child 8328: Main Thread]: I/jsep [1600935713663000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR]: stable -> closed
[task 2020-09-24T08:22:54.645Z] 08:22:54 INFO - PeerConnectionWrapper (pcLocal): Closed connection.
[task 2020-09-24T08:22:54.645Z] 08:22:54 INFO - GECKO(11060) | [Child 8328, Socket Thread] WARNING: MediaPipeline Transport failed. This is not properly cleaned up yet: file /builds/worker/checkouts/gecko/dom/media/webrtc/transportbridge/MediaPipelin
[task 2020-09-24T08:22:54.645Z] 08:22:54 INFO - Waiting for track {ace46e0f-c8f5-4533-b6f5-4ef69bccb984} (audio) to end.
[task 2020-09-24T08:22:54.645Z] 08:22:54 INFO - GECKO(11060) | e.cpp, line 428
[task 2020-09-24T08:22:54.646Z] 08:22:54 INFO - GECKO(11060) | [Child 8328, Socket Thread] WARNING: MediaPipeline Transport failed. This
[task 2020-09-24T08:22:54.646Z] 08:22:54 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndRemoteRollbackNoSubsequentRestart.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2020-09-24T08:22:54.646Z] 08:22:54 INFO - GECKO(11060) | is not properly cleaned up yet: file /builds/worker/checkouts/gecko/dom/media/webrtc/transportbridge/MediaPipeline.cpp, line 428
[task 2020-09-24T08:22:54.646Z] 08:22:54 INFO - GECKO(11060) | [Child 8328, Socket Thread] WARNING: MediaPipeline Transport failed. This is not properly cleaned up yet: file /builds/worker/checkouts/gecko/dom/media/webrtc/transportbridge/MediaPipeline.cpp, line 428
[task 2020-09-24T08:22:54.646Z] 08:22:54 INFO - GECKO(11060) | [Child 8328, Socket Thread] WARNING: MediaPipeline Transport failed. This is not properly cleaned up yet: file /builds/worker/checkouts/gecko/dom/media/webrtc/transportbridge/MediaPipeline.cpp, line 428
[task 2020-09-24T08:22:54.646Z] 08:22:54 INFO - GECKO(11060) | [Child 8328: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2100: CloseInt: Closing PeerConnectionImpl 0d761a5dc6f52939; ending call
[task 2020-09-24T08:22:54.647Z] 08:22:54 INFO - GECKO(11060) | [Child 8328: Main Thread]: I/jsep [1600935713667000 (id=2147484134 url=https://example.com/tests/dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndR]: stable -> closed
[task 2020-09-24T08:22:54.647Z] 08:22:54 INFO - PeerConnectionWrapper (pcRemote): Closed connection.
[task 2020-09-24T08:22:54.647Z] 08:22:54 INFO - TEST-FAIL | dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndRemoteRollbackNoSubsequentRestart.html | The author of the test has indicated that flaky timeouts are expected. Reason: WebRTC inherently depends on timeouts
[task 2020-09-24T08:22:54.647Z] 08:22:54 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndRemoteRollbackNoSubsequentRestart.html | Event target should be the correct track
[task 2020-09-24T08:22:54.647Z] 08:22:54 INFO - PeerConnectionWrapper (pcLocal) ended fired for track {44308787-35ba-4687-9a95-a2e95437d95e}
[task 2020-09-24T08:22:54.647Z] 08:22:54 INFO - TEST-PASS | dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndRemoteRollbackNoSubsequentRestart.html | Event target should be the correct track
[task 2020-09-24T08:22:54.647Z] 08:22:54 INFO - PeerConnectionWrapper (pcRemote) ended fired for track {ace46e0f-c8f5-4533-b6f5-4ef69bccb984}
[task 2020-09-24T08:22:54.648Z] 08:22:54 INFO - GECKO(11060) | MEMORY STAT | vsize 2103976MB | vsizeMaxContiguous 66357084MB | residentFast 147MB | heapAllocated 24MB
[task 2020-09-24T08:22:54.648Z] 08:22:54 INFO - TEST-OK | dom/media/tests/mochitest/test_peerConnection_restartIceLocalAndRemoteRollbackNoSubsequentRestart.html | took 61515ms
[task 2020-09-24T08:22:54.648Z] 08:22:54 INFO - GECKO(11060) | [GPU 8980, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:22:54.648Z] 08:22:54 INFO - GECKO(11060) | [GPU 8980, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:22:54.648Z] 08:22:54 INFO - GECKO(11060) | [GPU 8980, Compositor] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:22:54.648Z] 08:22:54 INFO - GECKO(11060) | [GPU 8980, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:22:54.648Z] 08:22:54 INFO - GECKO(11060) | [GPU 8980, Renderer] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:22:54.649Z] 08:22:54 INFO - GECKO(11060) | [GPU 8980, Compositor] WARNING: Failed to duplicate file handle for current process!: file /builds/worker/checkouts/gecko/ipc/glue/FileDescriptor.cpp, line 124
[task 2020-09-24T08:22:54.667Z] 08:22:54 INFO - TEST-START | dom/media/tests/mochitest/test_peerConnection_restartIceLocalRollback.html

Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.