Closed Bug 1867183 Opened 1 year ago Closed 6 months ago

Intermittent cubeb.one_duplex_one_input | Expected equality of these values: (Error initializing duplex cubeb stream)

Categories

(Core :: Audio/Video: cubeb, defect, P5)

defect

Tracking

()

RESOLVED FIXED
128 Branch
Tracking Status
firefox-esr115 --- unaffected
firefox121 --- unaffected
firefox122 --- wontfix
firefox123 --- wontfix
firefox126 --- wontfix
firefox127 --- wontfix
firefox128 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: padenot)

References

(Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [stockwell disable-recommended])

Attachments

(1 file)

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


[task 2023-11-29T02:53:40.845Z] 02:53:40     INFO -  TEST-START | cubeb.one_duplex_one_input
[task 2023-11-29T02:54:42.711Z] 02:54:42  WARNING -  TEST-UNEXPECTED-FAIL | cubeb.one_duplex_one_input | Expected equality of these values:
[task 2023-11-29T02:54:42.711Z] 02:54:42     INFO -    r
[task 2023-11-29T02:54:42.712Z] 02:54:42     INFO -      Which is: -1
[task 2023-11-29T02:54:42.712Z] 02:54:42     INFO -    CUBEB_OK
[task 2023-11-29T02:54:42.712Z] 02:54:42     INFO -      Which is: 0
[task 2023-11-29T02:54:42.712Z] 02:54:42     INFO -  Error initializing duplex cubeb stream
[task 2023-11-29T02:54:42.712Z] 02:54:42     INFO -   @ /builds/worker/checkouts/gecko/media/libcubeb/test/test_duplex.cpp:344
[task 2023-11-29T02:54:42.712Z] 02:54:42  WARNING -  TEST-UNEXPECTED-FAIL | cubeb.one_duplex_one_input | test completed (time: 61868ms)
[task 2023-11-29T02:54:42.713Z] 02:54:42     INFO -  TEST-START | cubeb.latency
[task 2023-11-29T02:54:42.713Z] 02:54:42     INFO -  TEST-PASS | cubeb.latency | test completed (time: 1ms)
[task 2023-11-29T02:54:42.713Z] 02:54:42     INFO -  TEST-START | cubeb.logging

Update

There have been 54 failures within the last 7 days:

  • 50 failures on OS X 10.15 WebRender opt/debug
  • 4 failures on OS X 10.15 WebRender Shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=441320616&repo=mozilla-central&lineNumber=2419.\

Karl, can you help us assign this to someone?
Thank you.

Flags: needinfo?(karlt)
Whiteboard: [stockwell needswork:owner]

This test was re-enabled late November in https://hg.mozilla.org/mozilla-central/rev/b263bc1c346d#l1.11
That revision doesn't build. This last revision landed for that bug builds and intermittently reproduces.

Perhaps Matthew might know something about this?

Flags: needinfo?(padenot)
Flags: needinfo?(kinetik)
Keywords: regression
Regressed by: 1864143
Summary: Intermittent cubeb.one_duplex_one_input | Expected equality of these values: → Intermittent cubeb.one_duplex_one_input | Expected equality of these values: (Error initializing duplex cubeb stream)
Flags: needinfo?(karlt)

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

Update

There have been 33 total failures within the last 7 days:

  • 24 failures on OS X 10.15 WebRender opt/debug
  • 9 failures on OS X 10.15 WebRender Shippable opt

Recent failure: https://treeherder.mozilla.org/logviewer?job_id=442558773&repo=autoland&lineNumber=2493

[task 2024-01-08T18:09:39.065Z] 18:09:39     INFO -  TEST-START | cubeb.one_duplex_one_input
[task 2024-01-08T18:10:41.056Z] 18:10:41  WARNING -  TEST-UNEXPECTED-FAIL | cubeb.one_duplex_one_input | Expected equality of these values:
[task 2024-01-08T18:10:41.056Z] 18:10:41     INFO -    r
[task 2024-01-08T18:10:41.056Z] 18:10:41     INFO -      Which is: -1
[task 2024-01-08T18:10:41.056Z] 18:10:41     INFO -    CUBEB_OK
[task 2024-01-08T18:10:41.056Z] 18:10:41     INFO -      Which is: 0
[task 2024-01-08T18:10:41.057Z] 18:10:41     INFO -  Error initializing duplex cubeb stream
[task 2024-01-08T18:10:41.057Z] 18:10:41     INFO -   @ /builds/worker/checkouts/gecko/media/libcubeb/test/test_duplex.cpp:344
[task 2024-01-08T18:10:41.057Z] 18:10:41  WARNING -  TEST-UNEXPECTED-FAIL | cubeb.one_duplex_one_input | test completed (time: 61992ms)
Whiteboard: [stockwell unknown] → [stockwell needswork:owner]

Update

There have been 41 total failures within the last 7 days:

  • 2 failures on OS X 10.15 WebRender Shippable opt
  • 39 failures on OS X 10.15 WebRender opt/ debug

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

[task 2024-01-27T14:31:44.596Z] 14:31:44     INFO -  TEST-START | cubeb.one_duplex_one_input
[task 2024-01-27T14:32:46.534Z] 14:32:46  WARNING -  TEST-UNEXPECTED-FAIL | cubeb.one_duplex_one_input | Expected equality of these values:
[task 2024-01-27T14:32:46.534Z] 14:32:46     INFO -    r
[task 2024-01-27T14:32:46.534Z] 14:32:46     INFO -      Which is: -1
[task 2024-01-27T14:32:46.534Z] 14:32:46     INFO -    CUBEB_OK
[task 2024-01-27T14:32:46.535Z] 14:32:46     INFO -      Which is: 0
[task 2024-01-27T14:32:46.535Z] 14:32:46     INFO -  Error initializing duplex cubeb stream
[task 2024-01-27T14:32:46.535Z] 14:32:46     INFO -   @ /builds/worker/checkouts/gecko/media/libcubeb/test/test_duplex.cpp:344
[task 2024-01-27T14:32:46.535Z] 14:32:46  WARNING -  TEST-UNEXPECTED-FAIL | cubeb.one_duplex_one_input | test completed (time: 61941ms)

Update

There have been 43 total failures within the last 7 days:

  • 3 failures on OS X 10.15 WebRender Shippable opt
  • 40 failures on OS X 10.15 WebRender opt/ debug

Recent log: https://treeherder.mozilla.org/logviewer?job_id=450666944&repo=autoland&lineNumber=1649

[task 2024-03-13T22:09:40.408Z] 22:09:40     INFO -  TEST-START | cubeb.one_duplex_one_input
[task 2024-03-13T22:10:42.865Z] 22:10:42  WARNING -  TEST-UNEXPECTED-FAIL | cubeb.one_duplex_one_input | Expected equality of these values:
[task 2024-03-13T22:10:42.865Z] 22:10:42     INFO -    r
[task 2024-03-13T22:10:42.865Z] 22:10:42     INFO -      Which is: -1
[task 2024-03-13T22:10:42.865Z] 22:10:42     INFO -    CUBEB_OK
[task 2024-03-13T22:10:42.865Z] 22:10:42     INFO -      Which is: 0
[task 2024-03-13T22:10:42.865Z] 22:10:42     INFO -  Error initializing duplex cubeb stream
[task 2024-03-13T22:10:42.865Z] 22:10:42     INFO -   @ /builds/worker/checkouts/gecko/media/libcubeb/test/test_duplex.cpp:344
[task 2024-03-13T22:10:42.865Z] 22:10:42  WARNING -  TEST-UNEXPECTED-FAIL | cubeb.one_duplex_one_input | test completed (time: 62459ms)

just fyi

Flags: needinfo?(padenot)
Flags: needinfo?(kinetik)
Flags: needinfo?(apehrson)
Whiteboard: [stockwell disable-recommended] → [stockwell needswork:owner]

Update

There have been 32 total failures within the last 7 days:

  • 29 failures on OS X 10.15 WebRender opt/ debug
  • 3 failures on OS X 10.15 WebRender Shippable opt

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=453816174&repo=mozilla-central&lineNumber=1593

[task 2024-04-07T11:42:59.933Z] 11:42:59     INFO -  TEST-START | cubeb.one_duplex_one_input
[task 2024-04-07T11:44:02.063Z] 11:44:02  WARNING -  TEST-UNEXPECTED-FAIL | cubeb.one_duplex_one_input | Expected equality of these values:
[task 2024-04-07T11:44:02.064Z] 11:44:02     INFO -    r
[task 2024-04-07T11:44:02.064Z] 11:44:02     INFO -      Which is: -1
[task 2024-04-07T11:44:02.064Z] 11:44:02     INFO -    CUBEB_OK
[task 2024-04-07T11:44:02.064Z] 11:44:02     INFO -      Which is: 0
[task 2024-04-07T11:44:02.064Z] 11:44:02     INFO -  Error initializing duplex cubeb stream
[task 2024-04-07T11:44:02.065Z] 11:44:02     INFO -   @ /builds/worker/checkouts/gecko/media/libcubeb/test/test_duplex.cpp:346
[task 2024-04-07T11:44:02.065Z] 11:44:02  WARNING -  TEST-UNEXPECTED-FAIL | cubeb.one_duplex_one_input | test completed (time: 62134ms)

With cubeb:4 logging:

[task 2024-04-10T22:41:18.558Z] 22:41:18     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:2393: Creating shared voiceprocessing storage.
[task 2024-04-10T22:41:49.510Z] 22:41:49     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:2207: Just created shared element #0. Took 30.95779s.
[task 2024-04-10T22:41:50.127Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:3433: (0x128fec800) Initializing input by device info: device_info { id: 47, flags: device_flags(DEV_INPUT) }
[task 2024-04-10T22:41:50.128Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:3451: (0x128fec800) Opening input side: rate 48000, channels 1, format Float32LE, layout 0x0, prefs VOICE, latency in frames 128, voice processing true.
[task 2024-04-10T22:41:50.128Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:3481: (0x128fec800) Input hardware description: AudioStreamBasicDescription { mSampleRate: 48000.0, mFormatID: 1819304813, mFormatFlags: 9, mBytesPerPacket: 8, mFramesPerPacket: 1, mBytesPerFrame: 8, mChannelsPerFrame: 2, mBitsPerChannel: 32, mReserved: 0 }
[task 2024-04-10T22:41:50.128Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:1400: The buffer frame size of AudioUnit 0x8031e1fc for INPUT is already 128
[task 2024-04-10T22:41:50.128Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:3601: (0x128fec800) Input audiounit init with device 47 successfully.
[task 2024-04-10T22:41:50.129Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:3630: (0x128fec800) Initialize output by device info: device_info { id: 111, flags: device_flags(DEV_OUTPUT | DEV_SELECTED_DEFAULT) }
[task 2024-04-10T22:41:50.129Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:3636: (0x128fec800) Opening output side: rate 48000, channels 2, format Float32LE, layout FRONT_LEFT | FRONT_RIGHT, prefs 0x0, latency in frames 128, voice processing true.
[task 2024-04-10T22:41:50.129Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:3666: (0x128fec800) Output hardware description: AudioStreamBasicDescription { mSampleRate: 48000.0, mFormatID: 1819304813, mFormatFlags: 41, mBytesPerPacket: 4, mFramesPerPacket: 1, mBytesPerFrame: 4, mChannelsPerFrame: 4, mBitsPerChannel: 32, mReserved: 0 }
[task 2024-04-10T22:41:50.130Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:3725: (0x128fec800 Using output device channel layout [FrontCenter]
[task 2024-04-10T22:41:50.130Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:3739: Incompatible channel layouts detected, setting up remixer
[task 2024-04-10T22:41:50.130Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mixer.rs:182: Creating a mixer with input channel count: 2, input layout: FRONT_LEFT | FRONT_RIGHT,out channel count: 1, output channels: [FrontCenter]
[task 2024-04-10T22:41:50.130Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mixer.rs:82: Create an floating type(f32) mixer
[task 2024-04-10T22:41:50.131Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:1400: The buffer frame size of AudioUnit 0x8031e1fc for OUTPUT is already 128
[task 2024-04-10T22:41:50.131Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:3816: (0x128fec800) Output audiounit init with device 111 successfully.
[task 2024-04-10T22:41:50.131Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb cubeb_resampler_internal.h:521:Input and output sample-rate match, target rate of 48000Hz
[task 2024-04-10T22:41:50.131Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:3886: AudioUnitInitialize/input rv=-66784
[task 2024-04-10T22:41:50.131Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:2836: (0x128fec800) Could not setup the audiounit stream.
[task 2024-04-10T22:41:50.132Z] 22:41:50     INFO -  [Parent 798: Unnamed thread 1229344b0]: E/cubeb mod.rs:1990: Device 47 (BlackHole 16ch) has 16 INPUT-channels
[task 2024-04-10T22:41:50.132Z] 22:41:50     INFO -  [Parent 798: Unnamed thread 1229344b0]: E/cubeb mod.rs:1990: Device 62 (BlackHole 2ch) has 2 INPUT-channels
[task 2024-04-10T22:41:50.132Z] 22:41:50     INFO -  [Parent 798: Unnamed thread 1229344b0]: E/cubeb mod.rs:1990: Device 105 (Mac mini Speakers) has 0 INPUT-channels
[task 2024-04-10T22:41:50.132Z] 22:41:50     INFO -  [Parent 798: Unnamed thread 1229344b0]: E/cubeb mod.rs:1990: Device 111 (28E850) has 0 INPUT-channels
[task 2024-04-10T22:41:50.133Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:2241: Recycling shared element #0. Nr of live elements now 0.
[task 2024-04-10T22:41:50.133Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:2284: Clearing shared voiceprocessing unit storage in 10s if still at generation 1.
[task 2024-04-10T22:41:50.133Z] 22:41:50     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:4656: Cubeb stream (0x128fec800) destroyed successful.
[task 2024-04-10T22:41:50.133Z] 22:41:50  WARNING -  TEST-UNEXPECTED-FAIL | cubeb.one_duplex_one_input | Expected equality of these values:
[task 2024-04-10T22:41:50.133Z] 22:41:50     INFO -    r
[task 2024-04-10T22:41:50.134Z] 22:41:50     INFO -      Which is: -1
[task 2024-04-10T22:41:50.134Z] 22:41:50     INFO -    CUBEB_OK
[task 2024-04-10T22:41:50.134Z] 22:41:50     INFO -      Which is: 0
[task 2024-04-10T22:41:50.134Z] 22:41:50     INFO -  Error initializing duplex cubeb stream
[task 2024-04-10T22:41:50.134Z] 22:41:50     INFO -   @ /builds/worker/checkouts/gecko/media/libcubeb/test/test_duplex.cpp:349
[task 2024-04-10T22:42:20.459Z] 22:42:20     INFO -  [Parent 798: Main Thread]: E/cubeb mod.rs:2253: Cleared 1 shared element. Took 30.329424s.
[task 2024-04-10T22:42:20.507Z] 22:42:20  WARNING -  TEST-UNEXPECTED-FAIL | cubeb.one_duplex_one_input | test completed (time: 61966ms)

Those 30s timeouts would in my experience mean that there is a macOS mic capture permission prompt showing.

Flags: needinfo?(apehrson)

Andreas, any updates on this one? It's on disable recommended bugs list with 172 total failures in the last 30 days: https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2024-04-18&endday=2024-05-18&tree=trunk&failurehash=all&bug=1867183
It should be disabled on mac if not fixed, thank you.

Flags: needinfo?(apehrson)

No updates from me. It seems like an infra or macOS issue.

Flags: needinfo?(apehrson)

Paul, could you please redirect this to someone to try and fix or disable this test on macosx1015? Thank you.

Flags: needinfo?(padenot)

I'll disable for now on 10.15. Those machines are going to be decom by EOY I'm told, let's not invest too much time there.

Flags: needinfo?(padenot)
Assignee: nobody → padenot
Status: NEW → ASSIGNED
Pushed by padenot@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/8ec210fe1ce6 Disable gtest cubeb.one_duplex_one_input on macOS 10.15. r=pehrsons,cubeb-reviewers
Status: ASSIGNED → RESOLVED
Closed: 6 months ago
Resolution: --- → FIXED
Target Milestone: --- → 128 Branch

The patch landed in nightly and beta is affected.
:padenot, is this bug important enough to require an uplift?

  • If yes, please nominate the patch for beta approval.
  • If no, please set status-firefox127 to wontfix.

For more information, please visit BugBot documentation.

Flags: needinfo?(padenot)
Flags: needinfo?(padenot)
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: