Debug-build terminal-spew: "ERROR [timestamp]: audio_thread_priority::rt_linux: Could not make thread real-time.
Categories
(Core :: Audio/Video, defect, P2)
Tracking
()
People
(Reporter: dholbert, Unassigned)
References
(Regression)
Details
(Keywords: regression)
Starting a few days ago, I've been seeing lots of spam like this to my terminal from my Nightly firefox installation:
ERROR 2019-06-27T16:51:36Z: audio_thread_priority::rt_linux: Could not make thread real-time.
ERROR 2019-06-27T16:51:37Z: audio_thread_priority::rt_linux: Could not make thread real-time.
ERROR 2019-06-27T16:51:37Z: audioipc_client: Could not promote audio threads to real-time during initialization.
ERROR 2019-06-27T16:51:37Z: audio_thread_priority::rt_linux: Could not make thread real-time.
ERROR 2019-06-27T16:51:37Z: audioipc_client: Could not promote audio threads to real-time during initialization.
This happens with a fresh profile. I'm on 64-bit Ubuntu 19.04 linux. My STR:
mkdir /tmp/foo; firefox -no-remote -profile /tmp/foo about:blank
This spams 21 lines of errors like those quoted above, before the Firefox window even shows up.
Reporter | ||
Comment 1•5 years ago
|
||
I'm guessing this might be related to bug 1560720 based on the mention of audio_thread_priority
and the timeline matching up (I've only been noticing this issue for a few days)...
Reporter | ||
Comment 2•5 years ago
|
||
(In reply to Daniel Holbert [:dholbert] from comment #1)
I'm guessing this might be related to bug 1560720
Ah, no - it's actually from a predecessor to that bug, bug 1429847.
Regression range:
Last good:
https://ftp.mozilla.org/pub/firefox/nightly/2019/06/2019-06-21-21-41-26-mozilla-central/firefox-69.0a1.en-US.linux-x86_64.tar.bz2
First bad:
https://ftp.mozilla.org/pub/firefox/nightly/2019/06/2019-06-22-21-47-27-mozilla-central/firefox-69.0a1.en-US.linux-x86_64.tar.bz2
This points at " Bug 1429847 - Add audio_thread_priority
to mozilla-central. r=kinetik"
Reporter | ||
Comment 3•5 years ago
|
||
Though, hmm, the logspew seems to have gone away in latest Nightly!
i.e. this nightly is good again:
https://ftp.mozilla.org/pub/firefox/nightly/2019/06/2019-06-27-09-36-36-mozilla-central/firefox-69.0a1.en-US.linux-x86_64.tar.bz2
I'm assuming this was due to the log-level change that :achronop flagged as related. So this is probably a dupe of that bug (i.e. fixed by that bug).
Comment 4•5 years ago
|
||
Yes, this is fixed. However, I'm a bit surprised that it does not work on your machine, on a recent Ubuntu. Are you not running rtkit ?
ps -ef | grep rtkit
should show something.
Comment 5•5 years ago
|
||
Also:
ps -eo rtprio,ni,pri,comm -T | grep AudioIPC
Should show something in the rtprio column (the first one). If it does not work, there should be a dash (-).
Reporter | ||
Comment 6•5 years ago
•
|
||
ps -ef | grep rtkit
turns up:
rtkit 1706 1 0 Jun21 ? 00:00:03 /usr/libexec/rtkit-daemon
And the AudioIPC command turns up:
$ ps -eo rtprio,ni,pri,comm -T | grep AudioIPC
- 0 19 AudioIPC Callba
- 0 19 AudioIPC Callba
- 0 19 AudioIPC Server
- 0 19 AudioIPC Server
10 - 50 AudioIPC Callba
- 0 19 AudioIPC Callba
- 0 19 AudioIPC Server
- 0 19 AudioIPC Server
- 0 19 AudioIPC Client
- 0 19 AudioIPC0
- 0 19 AudioIPC1
10 - 50 AudioIPC0
10 - 50 AudioIPC1
10 - 50 AudioIPC0
10 - 50 AudioIPC1
- 0 19 AudioIPC Client
10 - 50 AudioIPC0
10 - 50 AudioIPC1
- 0 19 AudioIPC Client
10 - 50 AudioIPC0
10 - 50 AudioIPC1
- 0 19 AudioIPC Client
10 - 50 AudioIPC0
10 - 50 AudioIPC1
- 0 19 AudioIPC Client
10 - 50 AudioIPC0
10 - 50 AudioIPC1
- 0 19 AudioIPC Client
10 - 50 AudioIPC0
10 - 50 AudioIPC1
10 - 50 AudioIPC0
10 - 50 AudioIPC1
- 0 19 AudioIPC Client
10 - 50 AudioIPC0
10 - 50 AudioIPC1
10 - 50 AudioIPC0
10 - 50 AudioIPC1
- 0 19 AudioIPC Callba
- 0 19 AudioIPC Callba
- 0 19 AudioIPC Server
- 0 19 AudioIPC Server
- 0 19 AudioIPC0
- 0 19 AudioIPC1
- 0 19 AudioIPC0
- 0 19 AudioIPC1
- 0 19 AudioIPC0
- 0 19 AudioIPC1
- 0 19 AudioIPC0
- 0 19 AudioIPC1
- 0 19 AudioIPC0
- 0 19 AudioIPC1
- 0 19 AudioIPC0
10 - 50 AudioIPC1
Also, note that our test runners (almost certainly on older Ubuntu) were hitting this as well -- see e.g. bug 1561680.
Comment 7•5 years ago
|
||
Ok this looks good then: some of the AudioIPC threads have an RT priority, I've removed the spew, and will investigate why we still see failures. It's probably because of the number of processes we run, but that's something we'll fix soon.
Thanks!
Reporter | ||
Comment 8•5 years ago
|
||
Thanks for taking a look. BTW, I do still see this terminalspew in debug builds (and it's early on -- it's the 12th line of output that I see).
Here's what it looks like there:
$ ./mach run --temp-profile
0:00.25 /scratch/work/builds/mozilla-central/obj/dist/bin/firefox -no-remote -profile /scratch/work/builds/mozilla-central/obj/tmp/profile-m1I5Cb
[8899, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80520012: file /scratch/work/builds/mozilla-central/mozilla/extensions/permissions/nsPermissionManager.cpp, line 2903
1561665523884 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: mozillaAddons
1561665523887 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: telemetry
1561665523891 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: resource://pdf.js/
1561665523893 addons.webextension.screenshots@mozilla.org WARN Loading extension 'screenshots@mozilla.org': Reading manifest: Invalid extension permission: about:reader*
[8899, GMPThread] WARNING: Failed to delete GMP storage directory: file /scratch/work/builds/mozilla-central/mozilla/dom/media/gmp/GMPServiceParent.cpp, line 1571
[8899, Main Thread] WARNING: 'mIndex >= Count()', file /scratch/work/builds/mozilla-central/mozilla/xpcom/ds/nsStringEnumerator.cpp, line 202
[8899, Main Thread] WARNING: Attempting to get a displayport from a content with no primary frame!: file /scratch/work/builds/mozilla-central/mozilla/layout/base/nsLayoutUtils.cpp, line 848
[Parent 8899, Main Thread] WARNING: '!aContent->GetComposedDoc()', file /scratch/work/builds/mozilla-central/mozilla/layout/base/nsCSSFrameConstructor.cpp, line 8679
Couldn't convert chrome URL: chrome://branding/locale/brand.properties
WARN 2019-06-27T19:58:52Z: audio_thread_priority::rt_linux: Could not make thread real-time.
WARN 2019-06-27T19:58:52Z: audioipc_client: Could not promote audio threads to real-time during initialization.
WARN 2019-06-27T19:58:52Z: audio_thread_priority::rt_linux: Could not make thread real-time.
WARN 2019-06-27T19:58:52Z: audioipc_client: Could not promote audio threads to real-time during initialization.
[Child 8964, Main Thread] WARNING: No active window: file /scratch/work/builds/mozilla-central/mozilla/js/xpconnect/src/XPCJSContext.cpp, line 662
[Parent 8899, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /scratch/work/builds/mozilla-central/mozilla/netwerk/cache/nsCacheService.cpp, line 169
Couldn't convert chrome URL: chrome://branding/locale/brand.properties
WARN 2019-06-27T19:58:55Z: audio_thread_priority::rt_linux: Could not make thread real-time.
WARN 2019-06-27T19:58:55Z: audioipc_client: Could not promote audio threads to real-time during initialization.
WARN 2019-06-27T19:58:55Z: audio_thread_priority::rt_linux: Could not make thread real-time.
WARN 2019-06-27T19:58:55Z: audioipc_client: Could not promote audio threads to real-time during initialization.
Reporter | ||
Comment 9•5 years ago
|
||
Given comment 8, maybe I'll un-dupe and leave this open (since the noise is still there, it's just debug-only now).
Comment 10•5 years ago
|
||
Maybe I need to use info!
and not warn!
in rust if we want this to be silent. Weird, though.
Updated•5 years ago
|
Updated•2 years ago
|
Updated•2 years ago
|
Description
•