1837115 - Perma TEST-UNEXPECTED-PASS | /webaudio/the-audio-api/the-audioworklet-interface/audioworkletnode-onerror.https.html | Test if |onprocessorerror| is called for a transfered object that cannot be deserialized on the AudioWorkletGlobalScope- expected TIMEOUT

Status: RESOLVED FIXED

(Core :: Web Audio, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2023-06-07T05:11:00.391Z] 05:11:00     INFO - TEST-OK | /webrtc/protocol/dtls-certificates.html | took 2681ms
[task 2023-06-07T05:11:00.391Z] 05:11:00     INFO - TEST-START | /webrtc/protocol/dtls-fingerprint-validation.html
[task 2023-06-07T05:11:00.392Z] 05:11:00     INFO - PID 7223 | [Child 7458: Socket Thread]: D/DataChannel Deregistered 2 from the SCTP stack.
[task 2023-06-07T05:11:00.392Z] 05:11:00     INFO - PID 7223 | [Child 7458: Socket Thread]: D/DataChannel Shutting down connection 7f3021172100, id 2
[task 2023-06-07T05:11:00.393Z] 05:11:00     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel DataChannelConnection labeled test(7f302116db00) (stream 1) changing ready state CLOSING -> CLOSED
[task 2023-06-07T05:11:00.393Z] 05:11:00     INFO - PID 4844 | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.sys.mjs", 399))
[task 2023-06-07T05:11:00.394Z] 05:11:00     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel operator(): sending ON_CHANNEL_CLOSED for test/: 1
[task 2023-06-07T05:11:00.394Z] 05:11:00     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel 7f302114dea0(7f302116db00): OnChannelClosed - Dispatching
[task 2023-06-07T05:11:00.395Z] 05:11:00     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel Deregistering connection ulp = 1
[task 2023-06-07T05:11:00.395Z] 05:11:00     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel Deleting DataChannelConnection 7f30212c2d00
[task 2023-06-07T05:11:00.396Z] 05:11:00     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel Deregistering connection ulp = 2
[task 2023-06-07T05:11:00.396Z] 05:11:00     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel Deleting DataChannelConnection 7f3021172100
[task 2023-06-07T05:11:00.397Z] 05:11:00     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel Calling usrsctp_finish 7f30229f2290
[task 2023-06-07T05:11:00.400Z] 05:11:00     INFO - PID 7223 | [Child 7458: Socket Thread]: I/mtransport NrIceCtx(PC:{13cbc12f-a3c7-437e-b035-231270785c61} 1686114660169921 (id=8589934594 url=http://web-platform.test:8000/webrtc/protocol/dtls-certificates.html)): Destroy
[task 2023-06-07T05:11:00.400Z] 05:11:00     INFO - PID 7223 | [Child 7458: Socket Thread]: I/mtransport NrIceCtx(PC:{a35b5e2d-95d3-4a0c-b648-cded2a47abd1} 1686114660173586 (id=8589934594 url=http://web-platform.test:8000/webrtc/protocol/dtls-certificates.html)): Destroy
[task 2023-06-07T05:11:00.401Z] 05:11:00     INFO - 
[task 2023-06-07T05:11:00.401Z] 05:11:00     INFO - TEST-PASS | /webaudio/the-audio-api/the-audioworklet-interface/audioworkletnode-onerror.https.html | Test if |onprocessorerror| is called for an exception thrown from the processor constructor. 
[task 2023-06-07T05:11:00.401Z] 05:11:00     INFO - TEST-UNEXPECTED-PASS | /webaudio/the-audio-api/the-audioworklet-interface/audioworkletnode-onerror.https.html | Test if |onprocessorerror| is called for a transfered object that cannot be deserialized on the AudioWorkletGlobalScope. - expected TIMEOUT
[task 2023-06-07T05:11:00.401Z] 05:11:00     INFO - TEST-INFO | expected TIMEOUT
[task 2023-06-07T05:11:00.401Z] 05:11:00     INFO - 
[task 2023-06-07T05:11:00.401Z] 05:11:00     INFO - TEST-UNEXPECTED-PASS | /webaudio/the-audio-api/the-audioworklet-interface/audioworkletnode-onerror.https.html | Test if |onprocessorerror| is called upon failure of process() method. - expected NOTRUN
[task 2023-06-07T05:11:00.401Z] 05:11:00     INFO - TEST-INFO | expected NOTRUN
[task 2023-06-07T05:11:00.401Z] 05:11:00     INFO - TEST-UNEXPECTED-OK | /webaudio/the-audio-api/the-audioworklet-interface/audioworkletnode-onerror.https.html | expected TIMEOUT
[task 2023-06-07T05:11:00.401Z] 05:11:00     INFO - TEST-INFO expected TIMEOUT | took 738ms
[task 2023-06-07T05:11:00.402Z] 05:11:00     INFO - PID 4844 | 1686114660380	Marionette	INFO	Stopped listening on port 36822
[task 2023-06-07T05:11:00.402Z] 05:11:00     INFO - Closing window c47016ea-d305-4b59-add5-4b2171d7f702
[task 2023-06-07T05:11:00.452Z] 05:11:00     INFO - PID 4844 | [Child 5026, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2023-06-07T05:11:00.454Z] 05:11:00     INFO - PID 4844 | [Child 5026, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2023-06-07T05:11:00.462Z] 05:11:00     INFO - PID 4844 | [Child 5026, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2023-06-07T05:11:00.470Z] 05:11:00     INFO - PID 4844 | [Child 5026, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2023-06-07T05:11:00.489Z] 05:11:00     INFO - PID 4844 | [Child 5026, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2023-06-07T05:11:00.492Z] 05:11:00     INFO - PID 4844 | [Child 5026, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2023-06-07T05:11:00.500Z] 05:11:00     INFO - PID 4844 | [Child 5026, Main Thread] WARNING: JSWindowActorChild::SendRawMessage (Conduits, ConduitClosed) not sent: !CanSend() || !mManager || !mManager->CanSend(): file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:61
[task 2023-06-07T05:11:00.587Z] 05:11:00     INFO - PID 4844 | [Child 5063, Main Thread] WARNING: DispatchEvent called on non-current inner window, dropping. Please check the window in the caller instead.: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowInner.cpp:4348
[task 2023-06-07T05:11:00.588Z] 05:11:00     INFO - PID 4844 | [Child 7072, Main Thread] WARNING: DispatchEvent called on non-current inner window, dropping. Please check the window in the caller instead.: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowInner.cpp:4348
[task 2023-06-07T05:11:00.632Z] 05:11:00     INFO - PID 4844 | [Parent 4844, Compositor] WARNING: Possibly dropping task posted to updater thread: file /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:371
[task 2023-06-07T05:11:00.641Z] 05:11:00     INFO - PID 4844 | [Child 7072, MediaTrackGrph] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3426
<...>
[task 2023-06-07T05:11:01.379Z] 05:11:01     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel Closing all channels (connection 7f3021153500)
[task 2023-06-07T05:11:01.379Z] 05:11:01     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel DataChannelConnection labeled transport_0 (7f3021153500) switching connection state CLOSED -> CLOSED
[task 2023-06-07T05:11:01.380Z] 05:11:01     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel Connection 7f3021153500: Sending outgoing stream reset for 0 streams
[task 2023-06-07T05:11:01.381Z] 05:11:01     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel No streams to reset
[task 2023-06-07T05:11:01.381Z] 05:11:01     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel DataChannelConnection labeled datachannel(7f30235a5a00) (stream 1) changing ready state CLOSING -> CLOSED
[task 2023-06-07T05:11:01.382Z] 05:11:01     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel operator(): sending ON_CHANNEL_CLOSED for datachannel/: 1
[task 2023-06-07T05:11:01.382Z] 05:11:01     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel 7f3022994f50(7f30235a5a00): OnChannelClosed - Dispatching
[task 2023-06-07T05:11:01.383Z] 05:11:01     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel Deregistering connection ulp = 1
[task 2023-06-07T05:11:01.383Z] 05:11:01     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel Deleting DataChannelConnection 7f3022928e00
[task 2023-06-07T05:11:01.384Z] 05:11:01     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel Deregistering connection ulp = 2
[task 2023-06-07T05:11:01.385Z] 05:11:01     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel Deleting DataChannelConnection 7f3021153500
[task 2023-06-07T05:11:01.385Z] 05:11:01     INFO - PID 7223 | [Child 7458: Main Thread]: D/DataChannel Calling usrsctp_finish 7f3021124560
[task 2023-06-07T05:11:01.386Z] 05:11:01     INFO - PID 7223 | [Child 7458: Socket Thread]: I/mtransport NrIceCtx(PC:{e8d029fb-0cbe-4db4-80f9-fd22104d5350} 1686114661081769 (id=8589934596 url=http://web-platform.test:8000/webrtc/protocol/dtls-fingerprint-validation.html)): Destroy
[task 2023-06-07T05:11:01.387Z] 05:11:01     INFO - .
[task 2023-06-07T05:11:01.387Z] 05:11:01     INFO - TEST-OK | /webrtc/protocol/dtls-fingerprint-validation.html | took 955ms

Comment 1

[Serban Stanca [:SerbanS]]

Hello Tooru! Could you please take a look at this bug? It seems to be perma on mozilla-central only, as it can be seen here, and I think it started once your changeset reached this repository.

Thank you!

Comment 2

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

Set release status flags based on info from the regressing bug 1831845

Comment 3

[Cosmin Sabou [:CosminS]]

Attachment: Bug 1837115 - Remove .ini file as expectations are no longer required.

Comment 4

[Tooru Fujisawa [:arai]]

I observed the TEST-UNEXPECTED-PASS even without my patch applied (on https://hg.mozilla.org/mozilla-central/rev/2f3136007f9a4fb31bc8bbddfe6e8dcb09e63075 , which is parent of bug 1831845 patches)
so I think this is pre-existing issue, possibly the test has some race, or something?
it would be better looking into the test itself and see what was actually happening with the timeout.

Comment 5

[Intermittent Failures Robot]

34 failures in 643 pushes (0.053 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-central: 29
• try: 5

Platform and build breakdown:

• linux1804-64-qr: 8
  • debug: 8
• linux1804-32-shippable-qr: 2
  • opt: 2
• linux1804-64-shippable-qr: 3
  • opt: 3
• android-em-7-0-x86_64-shippable-lite-qr: 2
  • opt: 2
• macosx1015-64-shippable-qr: 2
  • opt: 2
• android-em-7-0-x86_64-qr: 4
  • debug: 4
• linux1804-64-tsan-qr: 2
  • opt: 2
• windows11-64-2009-qr: 2
  • debug: 2
• macosx1015-64-qr: 1
  • debug: 1
• windows11-32-2009-qr: 1
  • debug: 1
• linux1804-64-asan-qr: 2
  • opt: 2
• windows11-64-2009-ccov-qr: 1
  • opt: 1
• linux1804-64-ccov-qr: 1
  • opt: 1
• windows11-64-2009-shippable-qr: 1
  • opt: 1
• windows11-32-2009-shippable-qr: 1
  • opt: 1
• android-em-7-0-x86_64-shippable-qr: 1
  • opt: 1

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

Comment 6

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/088d80e864aa
Remove .ini file as expectations are no longer required. r=aryx DONTBUILD

Comment 7

[Sandor Molnar[:smolnar]]

https://hg.mozilla.org/mozilla-central/rev/088d80e864aa

Comment 8

[Intermittent Failures Robot]

31 failures in 809 pushes (0.038 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-central: 28
• try: 3

Platform and build breakdown:

• linux1804-64-qr: 6
  • debug: 6
• windows11-64-2009-qr: 3
  • debug: 3
• macosx1015-64-qr: 1
  • debug: 1
• android-em-7-0-x86_64-qr: 2
  • debug: 2
• windows11-32-2009-qr: 1
  • debug: 1
• linux1804-64-tsan-qr: 1
  • opt: 1
• linux1804-64-ccov-qr: 1
  • opt: 1
• linux1804-64-asan-qr: 3
  • opt: 3
• windows11-64-2009-ccov-qr: 1
  • opt: 1
• linux1804-64-shippable-qr: 2
  • opt: 2
• windows11-64-2009-shippable-qr: 1
  • opt: 1
• linux1804-32-shippable-qr: 1
  • opt: 1
• windows11-32-2009-shippable-qr: 2
  • opt: 2
• android-em-7-0-x86_64-shippable-lite-qr: 2
  • opt: 2
• android-em-7-0-x86_64-shippable-qr: 1
  • opt: 1
• macosx1015-64-shippable-qr: 3
  • opt: 3

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

Comment 9

[Cosmin Sabou [:CosminS]]

No other failures/unexpected passes since the update. Closing.

Comment 10

[Intermittent Failures Robot]

65 failures in 3885 pushes (0.017 failures/push) were associated with this bug in the last 7 days.

This is the #12 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• mozilla-central: 57
• try: 8

Platform and build breakdown:

• linux1804-64-qr: 14
  • debug: 14
• linux1804-32-shippable-qr: 3
  • opt: 3
• linux1804-64-shippable-qr: 5
  • opt: 5
• android-em-7-0-x86_64-shippable-lite-qr: 4
  • opt: 4
• macosx1015-64-shippable-qr: 5
  • opt: 5
• android-em-7-0-x86_64-qr: 6
  • debug: 6
• linux1804-64-tsan-qr: 3
  • opt: 3
• windows11-64-2009-qr: 5
  • debug: 5
• macosx1015-64-qr: 2
  • debug: 2
• windows11-32-2009-qr: 2
  • debug: 2
• linux1804-64-asan-qr: 5
  • opt: 5
• windows11-64-2009-ccov-qr: 2
  • opt: 2
• linux1804-64-ccov-qr: 2
  • opt: 2
• windows11-64-2009-shippable-qr: 2
  • opt: 2
• windows11-32-2009-shippable-qr: 3
  • opt: 3
• android-em-7-0-x86_64-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1837115&startday=2023-06-05&endday=2023-06-11&tree=all