[pulseaudio-discuss] jack module cannot use real-time scheduling errors

Thu Jun 28 16:25:54 UTC 2018

On Wed, Jun 27, 2018 at 2:19 AM, Tanu Kaskinen <tanuk at iki.fi> wrote:
> On Thu, 2018-06-21 at 09:58 -0500, dag dg wrote:
>> I use pulse with jack via jackdbus. I've been trying to narrow down
>> the cause of a series of errors I've been seeing in my pulseaudio logs
>> for some time:
>>
>> Jun 21 08:43:46 localhost pulseaudio[1988]: W: [pulseaudio]
>> module-jack-sink.c: JACK error >Cannot use real-time scheduling
>> (RR/15)(1: Operation not permitted)<
>> Jun 21 08:43:46 localhost pulseaudio[1988]: W: [pulseaudio]
>> module-jack-source.c: JACK error >Cannot use real-time scheduling
>> (RR/15)(1: Operation not permitted)<
>> Jun 21 08:44:40 localhost pulseaudio[2596]: W: [pulseaudio]
>> module-jack-sink.c: JACK error >Cannot use real-time scheduling
>> (RR/15)(1: Operation not permitted)<
>> Jun 21 08:44:40 localhost pulseaudio[2596]: W: [pulseaudio]
>> module-jack-source.c: JACK error >Cannot use real-time scheduling
>> (RR/15)(1: Operation not permitted)<
>>
>> Running pulse in a higher verbosity I get:
>>
>> I: [pulseaudio] module-jack-sink.c: Successfully connected as
>> 'PulseAudio JACK Sink'
>> I: [pulseaudio] module-device-restore.c: Restoring volume for sink
>> jack_out: front-left: 45922 /  70%,   front-right: 45922 /  70%
>> I: [pulseaudio] module-device-restore.c: Restoring mute state for sink
>> jack_out: unmuted
>> W: [pulseaudio] sink.c: Default and alternate sample rates are the same.
>> I: [pulseaudio] sink.c: Created sink 3 "jack_out" with sample spec
>> float32le 2ch 48000Hz and channel map front-left,front-right
>> I: [pulseaudio] sink.c:     device.api = "jack"
>> I: [pulseaudio] sink.c:     device.description = "Jack sink
>> (PulseAudio JACK Sink)"
>> I: [pulseaudio] sink.c:     jack.client_name = "PulseAudio JACK Sink"
>> I: [pulseaudio] sink.c:     device.icon_name = "audio-card"
>> I: [pulseaudio] module-device-restore.c: Restoring volume for source
>> jack_out.monitor: front-left: 65536 / 100%,   front-right: 65536 /
>> 100%
>> I: [pulseaudio] source.c: Created source 5 "jack_out.monitor" with
>> sample spec float32le 2ch 48000Hz and channel map
>> front-left,front-right
>> I: [pulseaudio] source.c:     device.description = "Monitor of Jack
>> sink (PulseAudio JACK Sink)"
>> I: [pulseaudio] source.c:     device.class = "monitor"
>> I: [pulseaudio] source.c:     device.icon_name = "audio-input-microphone"
>> I: [pulseaudio] module-jack-sink.c: JACK thread starting up.
>> I: [pulseaudio] core-util.c: Successfully enabled SCHED_RR scheduling
>> for thread, with priority 9.
>> I: [jack-sink] core-util.c: Successfully enabled SCHED_RR scheduling
>> for thread, with priority 5.
>> I: [pulseaudio] module-jack-sink.c: JACK buffer size changed.
>> I: [pulseaudio] module-jack-sink.c: JACK thread starting up.
>> I: [pulseaudio] core-util.c: Successfully enabled SCHED_RR scheduling
>> for thread, with priority 9.
>> W: [pulseaudio] module-jack-sink.c: JACK error >Cannot use real-time
>> scheduling (RR/15)(1: Operation not permitted)<
>> W: [pulseaudio] module-jack-sink.c: JACK error
>> > JackClient::AcquireSelfRealTime error<
>>
>> I: [pulseaudio] module-jack-sink.c: JACK thread starting up.
>> I: [pulseaudio] core-util.c: Successfully enabled SCHED_RR scheduling
>> for thread, with priority 9.
>> I: [pulseaudio] module.c: Loaded "module-jack-sink" (index: #24;
>> argument: "connect=no channels=2").
>> I: [pulseaudio] module-jackdbus-detect.c: Successfully started module-jack-sink.
>> I: [pulseaudio] module-jack-source.c: Successfully connected as
>> 'PulseAudio JACK Source'
>> I: [pulseaudio] module-device-restore.c: Restoring volume for source
>> jack_in: front-left: 65536 / 100%,   front-right: 65536 / 100%
>> I: [pulseaudio] module-device-restore.c: Restoring mute state for
>> source jack_in: unmuted
>> W: [pulseaudio] source.c: Default and alternate sample rates are the same.
>> I: [pulseaudio] source.c: Created source 6 "jack_in" with sample spec
>> float32le 2ch 48000Hz and channel map front-left,front-right
>> I: [pulseaudio] source.c:     device.api = "jack"
>> I: [pulseaudio] source.c:     device.description = "Jack source
>> (PulseAudio JACK Source)"
>> I: [pulseaudio] source.c:     jack.client_name = "PulseAudio JACK Source"
>> I: [pulseaudio] source.c:     device.icon_name = "audio-input-microphone"
>> I: [pulseaudio] module-jack-source.c: JACK thread starting up.
>> I: [pulseaudio] core-util.c: Successfully enabled SCHED_RR scheduling
>> for thread, with priority 9.
>> I: [jack-source] core-util.c: Successfully enabled SCHED_RR scheduling
>> for thread, with priority 5.
>> I: [pulseaudio] module-jack-source.c: JACK thread starting up.
>> I: [pulseaudio] core-util.c: Successfully enabled SCHED_RR scheduling
>> for thread, with priority 9.
>> W: [pulseaudio] module-jack-source.c: JACK error >Cannot use real-time
>> scheduling (RR/15)(1: Operation not permitted)<
>> W: [pulseaudio] module-jack-source.c: JACK error
>> > JackClient::AcquireSelfRealTime error<
>>
>> I: [pulseaudio] module-jack-source.c: JACK thread starting up.
>> I: [pulseaudio] core-util.c: Successfully enabled SCHED_RR scheduling
>> for thread, with priority 9.
>> I: [pulseaudio] module.c: Loaded "module-jack-source" (index: #25;
>> argument: "connect=no channels=2").
>> I: [pulseaudio] module-jackdbus-detect.c: Successfully started
>> module-jack-source.
>>
>> I've played around with ulimit and cgroups but by distro
>> defaults(Fedora 28) seem to be fine as I can run processes via prlimit
>>
>> [user at localhost ~]$ sudo cat /etc/security/limits.d/95-jack.conf
>> # Default limits for users of jack-audio-connection-kit
>>
>> @jackuser - rtprio 70
>> @jackuser - memlock 4194304
>>
>> @pulse-rt - rtprio 20
>> @pulse-rt - nice -20
>> [user at localhost ~]$ prlimit --rtprio=70 --rttime=unlimited echo
>>
>> [user at localhost ~]$ echo $?
>> 0
>> [user at localhost ~]$ prlimit --rtprio=71 --rttime=unlimited echo
>> prlimit: failed to set the RTPRIO resource limit: Operation not permitted
>> [user at localhost ~]$ echo $?
>> 1
>>
>> So the settings appear to be correct yet the pulse jack module still
>> complains about not being able to properly set the RT priority? Any
>> insight would be appreciated.
>
> My guess is that when libjack creates a thread for the pulseaudio
> process, it tries to set priority 15 for the thread, but the pulseaudio
> process priority limit is something lower (probably 9, since that's the
> default). Try setting "rlimit-rtprio = 15" in /etc/pulse/daemon.conf.
>
> --
> Tanu
>
> https://liberapay.com/tanuk
> https://www.patreon.com/tanuk

Changing the rlimit-rtprio doesn't cause it to change the priority it
attempts to run as, but when I change the real time priority of the
jack daemon(via qjackctl) the jack pulse modules try to run at a
priority of 5 less than the priority of the jack daemon. For example
if I set the realtime priority to 30:

Jun 28 11:11:41 localhost pulseaudio[5920]: W: [pulseaudio] sink.c:
Default and alternate sample rates are the same.
Jun 28 11:11:41 localhost pulseaudio[5920]: W: [pulseaudio]
module-jack-sink.c: JACK error >Cannot use real-time scheduling
(RR/25)(1: Operation not permitted)<
Jun 28 11:11:41 localhost pulseaudio[5920]: W: [pulseaudio]
module-jack-sink.c: JACK error >JackClient::AcquireSelfRealTime error<
Jun 28 11:11:41 localhost pulseaudio[5920]: W: [pulseaudio] source.c:
Default and alternate sample rates are the same.
Jun 28 11:11:41 localhost pulseaudio[5920]: W: [pulseaudio]
module-jack-source.c: JACK error >Cannot use real-time scheduling
(RR/25)(1: Operation not permitted)<
Jun 28 11:11:41 localhost pulseaudio[5920]: W: [pulseaudio]
module-jack-source.c: JACK error >JackClient::AcquireSelfRealTime
error<
Jun 28 11:11:44 localhost pulseaudio[5920]: W: [pulseaudio] module.c:
After module unload, module 'module-null-sink' was still loaded!
Jun 28 11:11:49 localhost systemd[1621]: Starting Sound Service...
Jun 28 11:11:49 localhost rtkit-daemon[1071]: Successfully made thread
5973 of process 5973 (/usr/bin/pulseaudio) owned by '1000' high
priority at nice level -11.
Jun 28 11:11:49 localhost rtkit-daemon[1071]: Supervising 1 threads of
1 processes of 1 users.
Jun 28 11:11:51 localhost pulseaudio[5973]: W: [pulseaudio] sink.c:
Default and alternate sample rates are the same.
Jun 28 11:11:51 localhost pulseaudio[5973]: W: [pulseaudio]
module-jack-sink.c: JACK error >Cannot use real-time scheduling
(RR/25)(1: Operation not permitted)<
Jun 28 11:11:51 localhost pulseaudio[5973]: W: [pulseaudio]
module-jack-sink.c: JACK error >JackClient::AcquireSelfRealTime error<
Jun 28 11:11:51 localhost pulseaudio[5973]: W: [pulseaudio] source.c:
Default and alternate sample rates are the same.
Jun 28 11:11:51 localhost pulseaudio[5973]: W: [pulseaudio]
module-jack-source.c: JACK error >Cannot use real-time scheduling
(RR/25)(1: Operation not permitted)<
Jun 28 11:11:51 localhost pulseaudio[5973]: W: [pulseaudio]
module-jack-source.c: JACK error >JackClient::AcquireSelfRealTime
error<
Jun 28 11:11:51 localhost systemd[1621]: Started Sound Service.

you can see it attempts to set things at a priority of 25. If I change
it to 6 in qjackctl:

Jun 28 11:13:30 localhost pulseaudio[5973]: W: [pulseaudio] sink.c:
Default and alternate sample rates are the same.
Jun 28 11:13:30 localhost pulseaudio[5973]: W: [pulseaudio]
module-jack-sink.c: JACK error >Cannot use real-time scheduling
(RR/1)(1: Operation not permitted)<
Jun 28 11:13:30 localhost pulseaudio[5973]: W: [pulseaudio]
module-jack-sink.c: JACK error >JackClient::AcquireSelfRealTime error<
Jun 28 11:13:30 localhost pulseaudio[5973]: W: [pulseaudio] source.c:
Default and alternate sample rates are the same.
Jun 28 11:13:30 localhost pulseaudio[5973]: W: [pulseaudio]
module-jack-source.c: JACK error >Cannot use real-time scheduling
(RR/1)(1: Operation not permitted)<
Jun 28 11:13:30 localhost pulseaudio[5973]: W: [pulseaudio]
module-jack-source.c: JACK error >JackClient::AcquireSelfRealTime
error<
Jun 28 11:13:32 localhost pulseaudio[5973]: W: [pulseaudio] module.c:
After module unload, module 'module-null-sink' was still loaded!
Jun 28 11:13:37 localhost systemd[1621]: Starting Sound Service...
Jun 28 11:13:37 localhost rtkit-daemon[1071]: Successfully made thread
6038 of process 6038 (/usr/bin/pulseaudio) owned by '1000' high
priority at nice level -11.
Jun 28 11:13:37 localhost rtkit-daemon[1071]: Supervising 1 threads of
1 processes of 1 users.
Jun 28 11:13:40 localhost pulseaudio[6038]: W: [pulseaudio] sink.c:
Default and alternate sample rates are the same.
Jun 28 11:13:40 localhost pulseaudio[6038]: W: [pulseaudio]
module-jack-sink.c: JACK error >Cannot use real-time scheduling
(RR/1)(1: Operation not permitted)<
Jun 28 11:13:40 localhost pulseaudio[6038]: W: [pulseaudio]
module-jack-sink.c: JACK error >JackClient::AcquireSelfRealTime error<
Jun 28 11:13:40 localhost pulseaudio[6038]: W: [pulseaudio] source.c:
Default and alternate sample rates are the same.
Jun 28 11:13:40 localhost pulseaudio[6038]: W: [pulseaudio]
module-jack-source.c: JACK error >Cannot use real-time scheduling
(RR/1)(1: Operation not permitted)<
Jun 28 11:13:40 localhost pulseaudio[6038]: W: [pulseaudio]
module-jack-source.c: JACK error >JackClient::AcquireSelfRealTime
error<
Jun 28 11:13:40 localhost systemd[1621]: Started Sound Service.

you can see it tries to set it to a priority of 1(but I still see an error).

Here is the normal output I usually see:

Jun 28 11:14:29 localhost pulseaudio[6076]: W: [pulseaudio] sink.c:
Default and alternate sample rates are the same.
Jun 28 11:14:29 localhost pulseaudio[6076]: W: [pulseaudio]
module-jack-sink.c: JACK error >Cannot use real-time scheduling
(RR/15)(1: Operation not permitted)<
Jun 28 11:14:29 localhost pulseaudio[6076]: W: [pulseaudio]
module-jack-sink.c: JACK error >JackClient::AcquireSelfRealTime error<
Jun 28 11:14:29 localhost pulseaudio[6076]: W: [pulseaudio] source.c:
Default and alternate sample rates are the same.
Jun 28 11:14:29 localhost pulseaudio[6076]: W: [pulseaudio]
module-jack-source.c: JACK error >Cannot use real-time scheduling
(RR/15)(1: Operation not permitted)<
Jun 28 11:14:29 localhost pulseaudio[6076]: W: [pulseaudio]
module-jack-source.c: JACK error >JackClient::AcquireSelfRealTime
error<
Jun 28 11:14:32 localhost pulseaudio[6076]: W: [pulseaudio] module.c:
After module unload, module 'module-null-sink' was still loaded!
Jun 28 11:14:37 localhost systemd[1621]: Starting Sound Service...
Jun 28 11:14:37 localhost rtkit-daemon[1071]: Successfully made thread
6121 of process 6121 (/usr/bin/pulseaudio) owned by '1000' high
priority at nice level -11.
Jun 28 11:14:37 localhost rtkit-daemon[1071]: Supervising 1 threads of
1 processes of 1 users.
Jun 28 11:14:40 localhost pulseaudio[6121]: W: [pulseaudio] sink.c:
Default and alternate sample rates are the same.
Jun 28 11:14:40 localhost pulseaudio[6121]: W: [pulseaudio]
module-jack-sink.c: JACK error >Cannot use real-time scheduling
(RR/15)(1: Operation not permitted)<
Jun 28 11:14:40 localhost pulseaudio[6121]: W: [pulseaudio]
module-jack-sink.c: JACK error >JackClient::AcquireSelfRealTime error<
Jun 28 11:14:40 localhost pulseaudio[6121]: W: [pulseaudio] source.c:
Default and alternate sample rates are the same.
Jun 28 11:14:40 localhost pulseaudio[6121]: W: [pulseaudio]
module-jack-source.c: JACK error >Cannot use real-time scheduling
(RR/15)(1: Operation not permitted)<
Jun 28 11:14:40 localhost pulseaudio[6121]: W: [pulseaudio]
module-jack-source.c: JACK error >JackClient::AcquireSelfRealTime
error<
Jun 28 11:14:40 localhost systemd[1621]: Started Sound Service.

Note that this is being done via module-jackdbus-detect and jackdbus