Closed Bug 1713672 Opened 3 years ago Closed 3 years ago

Intermittent /webrtc/RTCDTMFSender-ontonechange.https.html | insertDTMF() with default duration and intertoneGap should fire tonechange events at the expected time - assert_between_inclusive: Expect tonechange event for "" to be fired approximately after

Categories

(Core :: WebRTC, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

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


[task 2021-05-31T18:29:56.476Z] 18:29:56     INFO - TEST-START | /webrtc/RTCDTMFSender-ontonechange.https.html
[task 2021-05-31T18:29:56.478Z] 18:29:56     INFO - Closing window 2b9c0be3-fc51-4c87-a1bf-f702cb7fddf6
[task 2021-05-31T18:29:56.489Z] 18:29:56     INFO - PID 3920 | [Child 6780: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2109: CloseInt: Closing PeerConnectionImpl {9034021f-1133-40cd-9ae3-a2d579b3b7d3}; ending call
[task 2021-05-31T18:29:56.490Z] 18:29:56     INFO - PID 3920 | [Child 6780: Main Thread]: I/jsep [{9034021f-1133-40cd-9ae3-a2d579b3b7d3} 1622485784203000 (id=2147483669 url=https://web-platform.test:8443/webrtc/RTCDTMFSender-]: stable -> closed
[task 2021-05-31T18:29:56.492Z] 18:29:56     INFO - PID 3920 | [Child 6780: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
[task 2021-05-31T18:29:56.492Z] 18:29:56     INFO - PID 3920 | [Child 6780: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2109: CloseInt: Closing PeerConnectionImpl {6aaeef9e-ffa7-4e6c-9acc-e04c2e7a17cd}; ending call
[task 2021-05-31T18:29:56.494Z] 18:29:56     INFO - PID 3920 | [Child 6780: Main Thread]: I/jsep [{6aaeef9e-ffa7-4e6c-9acc-e04c2e7a17cd} 1622485784207000 (id=2147483669 url=https://web-platform.test:8443/webrtc/RTCDTMFSender-]: stable -> closed
[task 2021-05-31T18:29:56.495Z] 18:29:56     INFO - PID 3920 | [Child 6780: WebRTCPD #1]: E/signaling [WebRTCPD #1|WebrtcAudioSessionConduit] AudioConduit.cpp:629: SendAudioFrame Engine not transmitting
[task 2021-05-31T18:29:56.629Z] 18:29:56     INFO - PID 3920 | [Child 2384: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:331: PeerConnectionImpl: PeerConnectionImpl constructor for
[task 2021-05-31T18:29:56.630Z] 18:29:56     INFO - PID 3920 | (unknown/INFO) insert '' (registry) succeeded:
[task 2021-05-31T18:29:56.631Z] 18:29:56     INFO - PID 3920 | (registry/INFO) Initialized registry
[task 2021-05-31T18:29:56.633Z] 18:29:56     INFO - PID 3920 | [Parent 9324: Socket Thread]: D/mtransport NrIceCtx static call to find local stun addresses
[task 2021-05-31T18:29:56.645Z] 18:29:56     INFO - PID 3920 | [Child 2384: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:331: PeerConnectionImpl: PeerConnectionImpl constructor for
[task 2021-05-31T18:29:56.646Z] 18:29:56     INFO - PID 3920 | [Parent 9324: Socket Thread]: D/mtransport NrIceCtx static call to find local stun addresses
[task 2021-05-31T18:29:56.650Z] 18:29:56     INFO - PID 3920 | [Child 2384: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:331: PeerConnectionImpl: PeerConnectionImpl constructor for
[task 2021-05-31T18:29:56.651Z] 18:29:56     INFO - PID 3920 | [Parent 9324: Socket Thread]: D/mtransport NrIceCtx static call to find local stun addresses
[task 2021-05-31T18:29:56.652Z] 18:29:56     INFO - PID 3920 | [Child 2384: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:331: PeerConnectionImpl: PeerConnectionImpl constructor for
[task 2021-05-31T18:29:56.653Z] 18:29:56     INFO - PID 3920 | [Parent 9324: Socket Thread]: D/mtransport NrIceCtx static call to find local stun addresses
[task 2021-05-31T18:29:56.655Z] 18:29:56     INFO - PID 3920 | (regis[Child 2384: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:75: OnStunAddrsAvailable: receiving (3) stun addrs
[task 2021-05-31T18:29:56.656Z] 18:29:56     INFO - PID 3920 | try/INFO) insert 'ice' (registry) succeeded: ice
[task 2021-05-31T18:29:56.657Z] 18:29:56     INFO - PID 3920 | (registry/INFO) insert 'ice.pref' (registry) succeeded: ice.pref
[task 2021-05-31T18:29:56.658Z] 18:29:56     INFO - PID 3920 | (registry/INFO) insert 'ice.pref.type' (registry) succeeded: ice.pref.type
[task 2021-05-31T18:29:56.660Z] 18:29:56     INFO - PID 3920 | (registry/INFO) insert 'ice.pref.type.srv_rflx' (UCHAR) succeeded: 0x64
[task 2021-05-31T18:29:56.661Z] 18:29:56     INFO - PID 3920 | (registry/INFO) insert 'ice.pref.type.peer_rflx' (UCHAR) succeeded: 0x6e
[task 2021-05-31T18:29:56.662Z] 18:29:56     INFO - PID 3920 | [Child 2384: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:75: OnStunAddrsAvailable: receiving (3) stun addrs
[task 2021-05-31T18:29:56.663Z] 18:29:56     INFO - PID 3920 | (registry/INFO) ins[Child 2384: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:75: OnStunAddrsAvailable: receiving (3) stun addrs
[task 2021-05-31T18:29:56.664Z] 18:29:56     INFO - PID 3920 | ert 'ice.pref.type.host' (UCHAR) succeeded: 0x[Child 2384: Main Thread]: I/signaling [main|PeerConnectionMedia] PeerConnectionMedia.cpp:75: OnStunAddrsAvailable: receiving (3) stun addrs
<...>
[task 2021-05-31T18:30:05.064Z] 18:30:05     INFO - PID 3920 | (ice/INFO) ICE-PEER(PC:{c73f9691-749b-4d9f-bcde-56568173b68c} 1622485804881000 (id=8589934594 url=https://web-platform.test:8443/webrtc/RTCDTMFSender-:default)/STREAM(PC:{c73f9691-749b-4d9f-bcde-56568173b68c} 1622485804881000 (id=8589934594 url=https://web-platform.test:8443/webrtc/RTCDTMFSender- transport-id=transport_0 - 8da1b99f:87937aec6ba15886b626a6e5ddae900d)/COMP(1)/CAND-PAIR(gsjP): cancelling all pairs but gsjP|IP4:10.49.40.169:63157/UDP|IP4:10.49.40.169:63154/UDP(host(IP4:10.49.40.169:63157/UDP)|candidate:0 1 UDP 2122252543 10.49.40.169 63154 typ host)
[task 2021-05-31T18:30:05.072Z] 18:30:05     INFO - ...
[task 2021-05-31T18:30:05.072Z] 18:30:05     INFO - TEST-OK | /upgrade-insecure-requests/gen/iframe-blank-inherit.meta/upgrade/worker-module.https.html | took 374ms
[task 2021-05-31T18:30:05.073Z] 18:30:05     INFO - TEST-START | /upgrade-insecure-requests/gen/iframe-blank-inherit.meta/upgrade/worklet-animation-import-data.https.html
[task 2021-05-31T18:30:05.074Z] 18:30:05     INFO - Closing window 30db3057-a9ad-4563-a139-36f1640160a6
[task 2021-05-31T18:30:05.076Z] 18:30:05     INFO - PID 3920 | (ice/INFO) ICE-PEER(PC:{c73f9691-749b-4d9f-bcde-56568173b68c} 1622485804881000 (id=8589934594 url=https://web-platform.test:8443/webrtc/RTCDTMFSender-:default)/ICE-STREAM(PC:{c73f9691-749b-4d9f-bcde-56568173b68c} 1622485804881000 (id=8589934594 url=https://web-platform.test:8443/webrtc/RTCDTMFSender- transport-id=transport_0 - 8da1b99f:87937aec6ba15886b626a6e5ddae900d): all active components have nominated candidate pairs
[task 2021-05-31T18:30:05.077Z] 18:30:05     INFO - PID 3920 | [Child 2384: Socket Thread]: D/mtransport Flow[transport_0(none)]; Layer[ice]: ICE Ready(PC:{c73f9691-749b-4d9f-bcde-56568173b68c} 1622485804881000 (id=8589934594 url=https://web-platform.test:8443/webrtc/RTCDTMFSender- transport-id=transport_0,1)
[task 2021-05-31T18:30:05.079Z] 18:30:05     INFO - PID 3920 | [Child 2384: Socket Thread]: D/mtransport Flow[transport_0(none)]; Layer[dtls]: Lower layer is now open; starting TLS
[task 2021-05-31T18:30:05.079Z] 18:30:05     INFO - PID 3920 | (ice/INFO) ICE-PEER(PC:{c73f9691-749b-4d9f-bcde-56568173b68c} 1622485804881000 (id=8589934594 url=https://web-platform.test:8443/webrtc/RTCDTMFSender-:default): all checks completed success=1 fail=0
<...>
[task 2021-05-31T18:30:05.212Z] 18:30:05     INFO - PID 3920 | [Child 2384: Main Thread]: I/jsep [{f1e85596-359a-49f8-885f-678af06b0e3d} 1622485804877000 (id=8589934594 url=https://web-platform.test:8443/webrtc/RTCDTMFSender-]: stable -> closed
[task 2021-05-31T18:30:05.213Z] 18:30:05     INFO - PID 3920 | [Child 2384: Main Thread]: E/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2778: GetStats: Found no pipelines matching selector.
[task 2021-05-31T18:30:05.214Z] 18:30:05     INFO - PID 3920 | [Child 2384: Main Thread]: I/signaling [main|PeerConnectionImpl] PeerConnectionImpl.cpp:2109: CloseInt: Closing PeerConnectionImpl {c73f9691-749b-4d9f-bcde-56568173b68c}; ending call
[task 2021-05-31T18:30:05.215Z] 18:30:05     INFO - PID 3920 | [Child 2384: Main Thread]: I/jsep [{c73f9691-749b-4d9f-bcde-56568173b68c} 1622485804881000 (id=8589934594 url=https://web-platform.test:8443/webrtc/RTCDTMFSender-]: stable -> closed
[task 2021-05-31T18:30:05.222Z] 18:30:05     INFO - 
[task 2021-05-31T18:30:05.222Z] 18:30:05     INFO - TEST-UNEXPECTED-FAIL | /webrtc/RTCDTMFSender-ontonechange.https.html | insertDTMF() with default duration and intertoneGap should fire tonechange events at the expected time - assert_between_inclusive: Expect tonechange event for "" to be fired approximately after 510 milliseconds expected a number greater than or equal to 510 and less than or equal to 4510 but got 509
[task 2021-05-31T18:30:05.222Z] 18:30:05     INFO - test_tone_change_events/</allEventsReceived</onToneChange<@https://web-platform.test:8443/webrtc/RTCDTMFSender-helper.js:123:33
[task 2021-05-31T18:30:05.222Z] 18:30:05     INFO - Test.prototype.step@https://web-platform.test:8443/resources/testharness.js:2087:25
[task 2021-05-31T18:30:05.222Z] 18:30:05     INFO - Test.prototype.step_func/<@https://web-platform.test:8443/resources/testharness.js:2114:35
[task 2021-05-31T18:30:05.234Z] 18:30:05     INFO - .............
[task 2021-05-31T18:30:05.234Z] 18:30:05     INFO - TEST-OK | /webrtc/RTCDTMFSender-ontonechange.https.html | took 8749ms
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.