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

Thu Jul 5 17:45:42 UTC 2018

Thanks Tanu.

I ran strace and dug through looking for relevant errors or warnings
and found the following:

19914 openat(AT_FDCWD,
"/usr/share/locale/en_US.utf8/LC_MESSAGES/pulseaudio.mo", O_RDONLY) =
-1 ENOENT (No such file or directory)
19914 openat(AT_FDCWD,
"/usr/share/locale/en_US/LC_MESSAGES/pulseaudio.mo", O_RDONLY) = -1
ENOENT (No such file or directory)
19914 openat(AT_FDCWD,
"/usr/share/locale/en.utf8/LC_MESSAGES/pulseaudio.mo", O_RDONLY) = -1
ENOENT (No such file or directory)
19914 openat(AT_FDCWD,
"/usr/share/locale/en/LC_MESSAGES/pulseaudio.mo", O_RDONLY) = -1
ENOENT (No such file or directory)
19914 futex(0x7fff7b7142a4, FUTEX_UNLOCK_PI) = -1 EPERM (Operation not
permitted)
19914 openat(AT_FDCWD, "/dev/urandom", O_RDONLY|O_NOCTTY|O_CLOEXEC) = 6
19914 fcntl(6, F_GETFD)                 = 0x1 (flags FD_CLOEXEC)
19914 read(6, "\260\374\227f", 4)       = 4
19914 close(6)                          = 0

19919 mprotect(0x7f9acc000000, 135168, PROT_READ|PROT_WRITE) = 0
19919 sendto(22, "\1\0\0\0\0\0\0\0", 8, MSG_NOSIGNAL, NULL, 0) = -1
ENOTSOCK (Socket operation on non-socket)
19919 write(22, "\1\0\0\0\0\0\0\0", 8)  = 8
19918 <... ppoll resumed> )             = 1 ([{fd=22, revents=POLLIN}])
19919 sched_setscheduler(19919, 0x40000002 /* SCHED_??? */, [9] <unfinished ...>
19918 read(22,  <unfinished ...>
19919 <... sched_setscheduler resumed> ) = 0
19918 <... read resumed> "\1\0\0\0\0\0\0\0", 8) = 8
19919 sched_setscheduler(19919, SCHED_FIFO, [15] <unfinished ...>
19918 ppoll([{fd=22, events=POLLIN}, {fd=18, events=POLLIN}, {fd=19,
events=POLLIN}], 3, NULL, NULL, 8 <unfinished ...>
19919 <... sched_setscheduler resumed> ) = -1 EPERM (Operation not permitted)
19919 futex(0x55a3a6754948, FUTEX_WAKE_PRIVATE, 1) = 1
19916 <... futex resumed> )             = 0
19919 futex(0x7f9af893e000, FUTEX_WAIT, 0, {tv_sec=2147,
tv_nsec=483647000} <unfinished ...>
19916 futex(0x55a3a67548f0, FUTEX_WAKE_PRIVATE, 1) = 0
19916 mmap(NULL, 134217728, PROT_NONE,
MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f9ac4000000
19916 munmap(0x7f9ac8000000, 67108864)  = 0

19921 prctl(PR_SET_NAME, "jack-source" <unfinished ...>
19914 mprotect(0x7f9ade062000, 524288, PROT_READ|PROT_WRITE <unfinished ...>
19921 <... prctl resumed> )             = 0
19914 <... mprotect resumed> )          = 0
19914 clone( <unfinished ...>
19921 sched_setscheduler(19921, 0x40000002 /* SCHED_??? */, [5]) = 0
19914 <... clone resumed> child_stack=0x7f9ade0e0d70,
flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID,
pare
nt_tidptr=0x7f9ade0e19d0, tls=0x7f9ade0e1700,
child_tidptr=0x7f9ade0e19d0) = 19922
19922 set_robust_list(0x7f9ade0e19e0, 24 <unfinished ...>
19914 nanosleep({tv_sec=0, tv_nsec=1000000},  <unfinished ...>
19922 <... set_robust_list resumed> )   = 0
19921 ppoll([{fd=35, events=POLLIN}, {fd=31, events=POLLIN}, {fd=32,
events=POLLIN}], 3, NULL, NULL, 8 <unfinished ...>
19922 sched_setscheduler(19922, 0x40000002 /* SCHED_??? */, [9]) = 0
19922 sched_setscheduler(19922, SCHED_FIFO, [15]) = -1 EPERM
(Operation not permitted)
19922 mmap(NULL, 134217728, PROT_NONE,
MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f9abc000000
19922 munmap(0x7f9ac0000000, 67108864)  = 0
19922 mprotect(0x7f9abc000000, 135168, PROT_READ|PROT_WRITE) = 0
19922 futex(0x55a3a675494c, FUTEX_WAKE_PRIVATE, 1) = 1
19916 <... futex resumed> )             = 0
19922 futex(0x7f9af893d000, FUTEX_WAIT, 0, {tv_sec=2147,
tv_nsec=483647000} <unfinished ...>
19916 futex(0x55a3a67548f0, FUTEX_WAKE_PRIVATE, 1) = 0
19916 ioctl(2, TCGETS, {B38400 opost isig icanon echo ...}) = 0
19916 write(2, "W: [pulseaudio] module-jack-sour"..., 127) = 127
19916 ioctl(2, TCGETS, {B38400 opost isig icanon echo ...}) = 0
19916 write(2, "W: [pulseaudio] module-jack-sour"..., 97) = 97
19916 futex(0x55a3a6754948, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
19914 <... nanosleep resumed> NULL)     = 0

Earlier I had noticed an error when it was trying to set RLIMIT_NICE
during startup:

prlimit64(0, RLIMIT_NOFILE, {rlim_cur=256, rlim_max=256}, NULL) = 0
prlimit64(0, RLIMIT_NICE, {rlim_cur=31, rlim_max=31}, NULL) = -1 EPERM
(Operation not permitted)
openat(AT_FDCWD, "/usr/share/locale/locale.alias", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=2997, ...}) = 0
read(3, "# Locale name alias data base.\n#"..., 4096) = 2997
read(3, "", 4096)                       = 0
close(3)                                = 0
openat(AT_FDCWD, "/usr/share/locale/en_US.utf8/LC_MESSAGES/libc.mo",
O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/en_US/LC_MESSAGES/libc.mo",
O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/en.utf8/LC_MESSAGES/libc.mo",
O_RDONLY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/share/locale/en/LC_MESSAGES/libc.mo", O_RDONLY)
= -1 ENOENT (No such file or directory)
prlimit64(0, RLIMIT_RTPRIO, {rlim_cur=9, rlim_max=9}, NULL) = 0
prlimit64(0, RLIMIT_RTTIME, {rlim_cur=200000, rlim_max=200000}, NULL) = 0

I double checked my /etc/security/limits.d/95-jack.conf had an entry
for the @jackuser and @pulse-rt groups which my user was a member of
both. As soon as I removed myself from pulse-rt things began to work
as expected regarding the RLIMIT-NICE

19914 prlimit64(0, RLIMIT_NOFILE, {rlim_cur=256, rlim_max=256}, NULL) = 0
19914 prlimit64(0, RLIMIT_NICE, {rlim_cur=31, rlim_max=31}, NULL) = 0
19914 prlimit64(0, RLIMIT_RTPRIO, {rlim_cur=9, rlim_max=9}, NULL) = 0
19914 prlimit64(0, RLIMIT_RTTIME, {rlim_cur=200000, rlim_max=200000}, NULL) = 0

But the other errors still persist. I'm not sure if it's a scheduler
permission issue or if I'm missing a dependency somewhere.

On Wed, Jul 4, 2018 at 4:09 AM, Tanu Kaskinen <tanuk at iki.fi> wrote:
> On Thu, 2018-06-28 at 11:25 -0500, dag dg wrote:
>> Changing the rlimit-rtprio doesn't cause it to change the priority it
>> attempts to run as,
>
> Yes, but it changes the allowed priority limit of the process. The
> default limit is 9, so that would explain why libjack can't set the
> priority to 15.
>
> However, you showed that libjack can't set the priority to even 1, so
> the rlimit-rtprio doesn't seem to be the problem (assuming that you
> didn't change rlimit-rtprio to 0 when testing).
>
> I don't know what the problem might be, since in your first email the
> verbose log showed that pulseaudio itself was able to set a realtime
> priority of 9. Maybe it was because pulseaudio is using rtkit and
> libjack is calling the kernel directly? There's probably some way of
> checking what the real rlimits are for a running process (probably some
> file under /proc).
>
> --
> Tanu
>
> https://liberapay.com/tanuk
> https://www.patreon.com/tanuk
> _______________________________________________
> pulseaudio-discuss mailing list
> pulseaudio-discuss at lists.freedesktop.org
> https://lists.freedesktop.org/mailman/listinfo/pulseaudio-discuss