On Thu, Jun 28, 2018 at 11:25 AM, dag dg <dagofthedofg at gmail.com> wrote: > 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 I ran a strace on the command and found the following output: [pid 10183] recvmsg(30, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="l\2\1\1\0\0\0\0002\3\0\0%\0\0\0\6\1s\0\6\0\0\0:1.266\0\0"..., iov_len=2048}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_CMSG_CLOEXEC) = 56 [pid 10183] recvmsg(30, {msg_namelen=0}, MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable) [pid 10183] close(30) = 0 [pid 10183] sched_setscheduler(10183, SCHED_FIFO, [15]) = -1 EPERM (Operation not permitted) [pid 10183] futex(0x5625cfbb26a8, FUTEX_WAKE_PRIVATE, 1) = 1 [pid 10183] futex(0x7fae139fb000, FUTEX_WAIT, 0, {tv_sec=2147, tv_nsec=483647000} <unfinished ...> [pid 10177] <... futex resumed> ) = 0 [pid 10177] futex(0x5625cfbb2650, FUTEX_WAKE_PRIVATE, 1) = 0 [pid 10177] prctl(PR_GET_NAME, "pulseaudio") = 0 [pid 10177] ioctl(2, TCGETS, {B38400 opost isig icanon echo ...}) = 0 [pid 10177] write(2, "W: [pulseaudio] module-jack-sink"..., 125W: [pulseaudio] module-jack-sink.c: JACK error >Cannot use real-time scheduling (RR/15)(1: Operation not permitted)< ) = 125 [pid 10177] ioctl(2, TCGETS, {B38400 opost isig icanon echo ...}) = 0 [pid 10177] write(2, "W: [pulseaudio] module-jack-sink"..., 95W: [pulseaudio] module-jack-sink.c: JACK error >JackClient::AcquireSelfRealTime error< ) = 95 [pid 10177] futex(0x5625cfbb26ac, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...> [pid 10183] <... futex resumed> ) = 0 [pid 10183] futex(0x7fae139fb000, FUTEX_WAIT, 0, {tv_sec=2147, tv_nsec=483647000} <unfinished ...> I tried tweaking some things via the user level systemd unit files in pulse and tweaking some cgroup settings but I get the same error every time(settings have all been reverted back to defaults).
