Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Pulseaudio gets real-time scheduling error on jack2, but not on jack1 #350

Closed
ndrspcfd opened this issue Jun 6, 2018 · 24 comments
Closed

Comments

@ndrspcfd
Copy link

ndrspcfd commented Jun 6, 2018

Hi,

Tl;dr: with a straightforward jack2 install jackd itself gets RT prio fine but generates permissions errors when I set pulseaudio bridge's RT prio; Jack1's jackd successfully sets the bridge's RT prio, and doesn't generate these errors. Seems like a jack2 bug? Details below.

I'm using the distro's jackd2 giving me jackdmp 1.9.12

I start jackd with exec /usr/bin/jackd -R -P 95 -u -t 5000000 -d alsa -d hw:USB -p 64 -n 2 -r 48000 and it reports: JACK server starting in realtime mode with priority 95 with no further problems.

Then I start /usr/bin/pulseaudio --high-priority --realtime --verbose --exit-idle-time=85000 --file=./pr.pa -n (pr.pa is essentially a copy of the pulse bridge script used by cadence) and it complains:

I: [pulseaudio] module-jack-source.c: JACK thread starting up.
I: [pulseaudio] core-util.c: Successfully enabled SCHED_RR scheduling for thread, with priority 91.
I: [jack-source] core-util.c: Successfully enabled SCHED_RR scheduling for thread, with priority 87.
I: [pulseaudio] module-jack-source.c: JACK thread starting up.
I: [pulseaudio] core-util.c: Successfully enabled SCHED_RR scheduling for thread, with priority 91.
W: [pulseaudio] module-jack-source.c: JACK error >Cannot use real-time scheduling (RR/90)(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 91.
I: [pulseaudio] module-jack-source.c: Connecting PulseAudio JACK Source:front-left to system:capture_1

(I verified that an error is really being returned from jack causing the bolded JACK errors above, at https://github.com/jackaudio/jack2/blob/master/posix/JackPosixThread.cpp#L237)

If I then kill everything, do apt-get install libjack0, changing nothing else, and run the same commands it works without error. I checked the RT prio is actually set and it's not just an ignored error, by looking at htop (RT prios bolded) :

4719 user -92 -11 581M 171M 145M S 25 0:03.47 /usr/bin/pulseaudio --high-priority --realtime --verbose --exit-idle-time=85000 --file=./pr.pa -n

4683 user -96 0 213M 63556 45108 S 1.3 0.2 0:04.74 /usr/bin/jackd -R -P 95 -u -t 5000000 -d alsa -d hw:USB -p 64 -n 2 -r 48000 `

The pulseaudio output is:

I: [pulseaudio] module-jack-source.c: JACK thread starting up.
I: [pulseaudio] core-util.c: Successfully enabled SCHED_RR scheduling for thread, with priority 91.
I: [jack-source] core-util.c: Successfully enabled SCHED_RR scheduling for thread, with priority 87.
I: [pulseaudio] module-jack-source.c: JACK thread starting up.
I: [pulseaudio] core-util.c: Successfully enabled SCHED_RR scheduling for thread, with priority 91.
I:

uname -a is

Linux monstro 4.15.0-041500-lowlatency #201802011154 SMP PREEMPT Thu Feb 1 11:58:07 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux

So, since jackd1 and its lib don't give me this error and just swapping to jackd2 does give me the error, it looks like a bug in jackd2. Is this correct?

@nemanjan00
Copy link

nemanjan00 commented Jun 22, 2018

I also have this same problem on arch with linux-ck. (did not test with default kernel yet)

Edit:

Also with default kernel...

Edit 2:

I think reinstalling jack2-dbus solved this for me.

@nemanjan00
Copy link

Nope, for me it was problem of timing.

Jack2 needs to be started a little bit before starting pulse, for it to work.

@dvzrv
Copy link
Contributor

dvzrv commented Jan 22, 2019

Hm, I'm seeing the same problem with both jack and jack2 on Arch Linux.

@miquecg
Copy link

miquecg commented Feb 12, 2019

I'm also seeing the same messages in system logs. My setup is jack2-dbus on Arch Linux with pulseaudio-jack installed.

I start jack server with Cadence whenever I want to use it and pulseaudio is successfully routed through jack. According to Cadence logs, jack gets realtime priorirty.

My user belongs to realtime group (it's not in audio) which has the following limits:

➜ % ~  cat /etc/security/limits.d/99-realtime-privileges.conf 
@realtime - rtprio 98
@realtime - memlock unlimited

Everything looks fine but for some reason I can also see these messages on the logs, although I think it's not big deal for me. I'm mainly using jack with MIDI and VST instruments. Is there any reason this could affect jack's realtime priority or add more latency while monitoring?

@dvzrv
Copy link
Contributor

dvzrv commented Feb 12, 2019

Further looking into this, this could be a general problem of pulseaudio acquiring realtime. That this error message doesn't appear on jack1 could be due to the fact, that jack1 doesn't have a dbus interface, from which pulseaudio acquires information regarding its realtime use. It might also be an implementational difference between the jack1/jack2 API.

I think this should be elaborated upon further with the pulseaudio developers, as there's a bug report for that already on their side, too.

@falkTX
Copy link
Member

falkTX commented Sep 18, 2019

Fixed with #499

@falkTX falkTX closed this as completed Sep 18, 2019
@terencode
Copy link

@falkTX I still have the issue with jack2 built from the develop branch:

Jack: jack_client_open PulseAudio JACK Sink
Jack: JackLibGlobals Init 0
Jack: JackLibGlobals
Jack: JackPosixThread::StartImp : create non RT thread
Jack: JackPosixThread::ThreadHandler : start
Jack: JackGenericClientChannel::ServerCheck = default
Jack: JackClientSocket::Connect : addr.sun_path /dev/shm/jack_default_1000_0
Jack: JackClientSocket::Close
Jack: JackLibClient::JackLibClient table = 4d1d6410
Jack: JackLibClient::Open name = PulseAudio JACK Sink
Jack: JackSocketClientChannel::Open name = PulseAudio JACK Sink
Jack: JackClientSocket::Connect : addr.sun_path /dev/shm/jack_default_1000_0
Jack: JackServerSocket::Bind : addr.sun_path /dev/shm/jack_PulseAudio JACK Sink_1000_0
Jack: JackSocketClientChannel::Start
Jack: JackPosixThread::StartImp : create non RT thread
Jack: JackPosixThread::ThreadHandler : start
Jack: JackSocketClientChannel::Init
Jack: JackServerSocket::Close /dev/shm/jack_PulseAudio JACK Sink_1000_0
Jack: JackClient::ClientNotify ref = 0 name = system notify = 0
Jack: JackClient::AddClient name = system, ref = 0
Jack: JackLinuxFutex::Connect name = jack_sem.1000_default_system
Jack: JackClient::ClientNotify ref = 1 name = freewheel notify = 0
Jack: JackClient::AddClient name = freewheel, ref = 1
Jack: JackLinuxFutex::Connect name = jack_sem.1000_default_freewheel
Jack: JackClient::ClientNotify ref = 2 name = dbusapi notify = 0
Jack: JackClient::AddClient name = dbusapi, ref = 2
Jack: JackLinuxFutex::Connect name = jack_sem.1000_default_dbusapi
Jack: JackShmReadWritePtr::Init 1 -1
Jack: Succeeded in locking 1187 byte memory area
Jack: JackShmReadWritePtr::Init 0 -1
Jack: Succeeded in locking 47664026 byte memory area
Jack: JackShmReadWritePtr1::Init 2 -1
Jack: Succeeded in locking 426 byte memory area
Jack: JackClient::SetupDriverSync driver sem in flush mode
Jack: JackLinuxFutex::Connect name = jack_sem.1000_default_PulseAudio JACK Sink
Jack: Clock source : system clock via clock_gettime
Jack: JackLibClient::Open name = PulseAudio JACK Sink refnum = 3
Jack: JackClient::PortRegister ref = 3 name = PulseAudio JACK Sink:front-left type = 32 bit float mono audio port_index = 5
Jack: JackClient::PortRegister ref = 3 name = PulseAudio JACK Sink:front-right type = 32 bit float mono audio port_index = 6
Jack: jack_set_thread_init_callback ext_client 4d181b20 client 4d181b20
Jack: JackClient::Activate
Jack: JackPosixThread::StartImp : create non RT thread
Jack: JackPosixThread::ThreadHandler : start
Jack: JackClient::kBufferSizeCallback buffer_size = 64
Jack: JackClient::Init calling client thread init callback
Jack: JackClient::Init : period = 1333 computation = 500 constraint = 1333
Jack: JackPosixThread::AcquireRealTimeImp priority = 55
Jack: pthread_setschedparam() failed (1), trying with SCHED_RESET_ON_FORK.
W: [pulseaudio] module-jack-sink.c: JACK error >Cannot use real-time scheduling (RR/55) (1: Operation not permitted)<
W: [pulseaudio] module-jack-sink.c: JACK error >JackClient::AcquireSelfRealTime error<
Jack: JackClient::ClientNotify ref = 3 name = PulseAudio JACK Sink notify = 2
Jack: JackClient::kActivateClient name = PulseAudio JACK Sink ref = 3
Jack: JackClient::Init calling client thread init callback
Jack: JackClient::Connect src = PulseAudio JACK Sink:front-left dst = system:playback_1
Jack: JackClient::ClientNotify ref = 3 name = PulseAudio JACK Sink notify = 18
Jack: JackClient::Connect src = PulseAudio JACK Sink:front-right dst = system:playback_2
Jack: WaitGraphChange...
Jack: JackClient::ClientNotify ref = 3 name = PulseAudio JACK Sink notify = 18
Jack: JackClient::ClientNotify ref = 3 name = PulseAudio JACK Sink notify = 18
Jack: jack_client_open PulseAudio JACK Source
Jack: JackGenericClientChannel::ServerCheck = default
Jack: JackClientSocket::Connect : addr.sun_path /dev/shm/jack_default_1000_0
Jack: JackClientSocket::Close
Jack: JackLibClient::JackLibClient table = 4d1d6410
Jack: JackLibClient::Open name = PulseAudio JACK Source
Jack: JackSocketClientChannel::Open name = PulseAudio JACK Source
Jack: JackClientSocket::Connect : addr.sun_path /dev/shm/jack_default_1000_0
Jack: JackServerSocket::Bind : addr.sun_path /dev/shm/jack_PulseAudio JACK Source_1000_0
Jack: JackSocketClientChannel::Start
Jack: JackPosixThread::StartImp : create non RT thread
Jack: JackPosixThread::ThreadHandler : start
Jack: JackSocketClientChannel::Init
Jack: JackServerSocket::Close /dev/shm/jack_PulseAudio JACK Source_1000_0
Jack: JackClient::ClientNotify ref = 0 name = system notify = 0
Jack: JackClient::AddClient name = system, ref = 0
Jack: JackLinuxFutex::Connect name = jack_sem.1000_default_system
Jack: Already connected name = system
Jack: JackClient::ClientNotify ref = 1 name = freewheel notify = 0
Jack: JackClient::AddClient name = freewheel, ref = 1
Jack: JackLinuxFutex::Connect name = jack_sem.1000_default_freewheel
Jack: Already connected name = freewheel
Jack: JackClient::ClientNotify ref = 2 name = dbusapi notify = 0
Jack: JackClient::AddClient name = dbusapi, ref = 2
Jack: JackLinuxFutex::Connect name = jack_sem.1000_default_dbusapi
Jack: Already connected name = dbusapi
Jack: JackClient::ClientNotify ref = 4 name = PulseAudio JACK Source notify = 0
Jack: JackClient::AddClient name = PulseAudio JACK Source, ref = 4
Jack: JackLinuxFutex::Connect name = jack_sem.1000_default_PulseAudio JACK Source
Jack: JackClient::kAddClient fName = PulseAudio JACK Sink name = PulseAudio JACK Source
Jack: JackClient::ClientNotify ref = 3 name = PulseAudio JACK Sink notify = 0
Jack: JackClient::AddClient name = PulseAudio JACK Sink, ref = 3
Jack: JackLinuxFutex::Connect name = jack_sem.1000_default_PulseAudio JACK Sink
Jack: Already connected name = PulseAudio JACK Sink
Jack: JackShmReadWritePtr1::Init 3 -1
Jack: Succeeded in locking 426 byte memory area
Jack: JackClient::SetupDriverSync driver sem in flush mode
Jack: JackLinuxFutex::Connect name = jack_sem.1000_default_PulseAudio JACK Source
Jack: Already connected name = PulseAudio JACK Source
Jack: Clock source : system clock via clock_gettime
Jack: JackLibClient::Open name = PulseAudio JACK Source refnum = 4
Jack: JackClient::PortRegister ref = 4 name = PulseAudio JACK Source:front-left type = 32 bit float mono audio port_index = 7
Jack: JackClient::PortRegister ref = 4 name = PulseAudio JACK Source:front-right type = 32 bit float mono audio port_index = 8
Jack: jack_set_thread_init_callback ext_client 4d2094a0 client 4d2094a0
Jack: JackClient::ClientNotify ref = 3 name = PulseAudio JACK Sink notify = 18
Jack: JackClient::Activate
Jack: JackPosixThread::StartImp : create non RT thread
Jack: JackClient::ClientNotify ref = 3 name = PulseAudio JACK Sink notify = 18
Jack: JackPosixThread::ThreadHandler : start
Jack: JackClient::kBufferSizeCallback buffer_size = 64
Jack: JackClient::Init calling client thread init callback
Jack: JackClient::Init : period = 1333 computation = 500 constraint = 1333
Jack: JackPosixThread::AcquireRealTimeImp priority = 55
Jack: pthread_setschedparam() failed (1), trying with SCHED_RESET_ON_FORK.
W: [pulseaudio] module-jack-source.c: JACK error >Cannot use real-time scheduling (RR/55) (1: Operation not permitted)<
W: [pulseaudio] module-jack-source.c: JACK error >JackClient::AcquireSelfRealTime error<
Jack: JackClient::ClientNotify ref = 4 name = PulseAudio JACK Source notify = 2
Jack: JackClient::kActivateClient name = PulseAudio JACK Source ref = 4
Jack: JackClient::Init calling client thread init callback
Jack: JackClient::Connect src = system:capture_1 dst = PulseAudio JACK Source:front-left
Jack: JackClient::ClientNotify ref = 3 name = PulseAudio JACK Sink notify = 18
Jack: JackClient::ClientNotify ref = 4 name = PulseAudio JACK Source notify = 18
Jack: JackClient::ClientNotify ref = 3 name = PulseAudio JACK Sink notify = 18
Jack: JackClient::Connect src = system:capture_2 dst = PulseAudio JACK Source:front-right
Jack: WaitGraphChange...
Jack: JackClient::ClientNotify ref = 3 name = PulseAudio JACK Sink notify = 18
Jack: JackClient::ClientNotify ref = 4 name = PulseAudio JACK Source notify = 18
Jack: JackClient::ClientNotify ref = 4 name = PulseAudio JACK Source notify = 18
Jack: JackClient::ClientNotify ref = 3 name = PulseAudio JACK Sink notify = 18

@falkTX
Copy link
Member

falkTX commented Sep 20, 2019

ah damn it.
I see this is using new code, so indeed not fixed.

@falkTX falkTX reopened this Sep 20, 2019
@imaami
Copy link
Contributor

imaami commented Sep 23, 2019

If I set rlimit-rtprio = 10 in /etc/pulse/daemon.conf (i.e., configure PulseAudio's max RT priority as lower than what JACK wants on my machine) then I get the same errors, too. But setting rlimit-rtprio = 99 in /etc/pulse/daemon.conf (which is what I normally have there) makes it work.

Notice that before the JACK fix the rlimit-rtprio = 99 PulseAudio config did not help.

I think this is a matter of PulseAudio being strict with its scheduler parameters. I'm honestly not sure which component to blame here. Maybe this has something to do with cgroups? Should this be treated as an end user configuration error equivalent to not having the right stuff in /etc/security/limits.conf?

Oh and @terencode, can you see if setting rlimit-rtprio = 99 in /etc/pulse/daemon.conf fixes it for you, too?

@terencode
Copy link

Great investigation imaami, this works.

@imaami
Copy link
Contributor

imaami commented Sep 23, 2019

Great investigation imaami, this works.

Glad to hear, and thanks for the original comment! It revealed an interesting corner case to investigate. :)

@terencode
Copy link

Didn't do much but hey ^^

@terencode
Copy link

@imaami I don't know what changed but it's not working anymore. I just have rlimit-rtprio = 60 set but jack shows the same error as before, even with 99.

@imaami
Copy link
Contributor

imaami commented Nov 11, 2019

@imaami I don't know what changed but it's not working anymore. I just have rlimit-rtprio = 60 set but jack shows the same error as before, even with 99.

Are you sure you're still running a jack build that has the fix? I got recently hit with this bug again, but it turned out to just be Debian having overwritten my locally-built package with their 1.9.12-based one. Rebuilding from jack2 upstream fixed it.

@terencode
Copy link

I did check that and the verbose log confirm it is the fixed version unfortunately:

nov. 11 12:37:59 terence-arch pulseaudio[1835]: W: [pulseaudio] module-jack-sink.c: JACK error >JackClient::AcquireSelfRealTime error<
nov. 11 12:37:59 terence-arch pulseaudio[1835]: W: [pulseaudio] module-jack-sink.c: JACK error >Cannot use real-time scheduling (RR/55) (1: Operation not permitted)<
nov. 11 12:37:59 terence-arch pulseaudio[1835]: Jack: pthread_setschedparam() failed (1), trying with SCHED_RESET_ON_FORK.
nov. 11 12:37:59 terence-arch pulseaudio[1835]: Jack: JackPosixThread::AcquireRealTimeImp priority = 55
nov. 11 12:37:59 terence-arch pulseaudio[1835]: Jack: JackClient::Init : period = 1333 computation = 500 constraint = 1333
nov. 11 12:37:59 terence-arch pulseaudio[1835]: Jack: JackClient::Init calling client thread init callback
nov. 11 12:37:59 terence-arch pulseaudio[1835]: Jack: JackClient::kBufferSizeCallback buffer_size = 64
nov. 11 12:37:59 terence-arch pulseaudio[1835]: Jack: JackPosixThread::ThreadHandler : start
nov. 11 12:37:59 terence-arch pulseaudio[1835]: Jack: JackPosixThread::StartImp : create non RT thread
nov. 11 12:37:59 terence-arch pulseaudio[1835]: Jack: JackClient::Activate
nov. 11 12:37:59 terence-arch pulseaudio[1835]: Jack: jack_set_thread_init_callback ext_client 3a7cff0 client 3a7cff0
nov. 11 12:37:59 terence-arch pulseaudio[1835]: Jack: JackClient::PortRegister ref = 3 name = PulseAudio JACK Sink:front-right type = 32 bit float mono audio port_index = 6
nov. 11 12:37:59 terence-arch pulseaudio[1835]: Jack: JackClient::PortRegister ref = 3 name = PulseAudio JACK Sink:front-left type = 32 bit float mono audio port_index = 5
nov. 11 12:37:59 terence-arch pulseaudio[1835]: Jack: JackLibClient::Open name = PulseAudio JACK Sink refnum = 3
nov. 11 12:37:59 terence-arch pulseaudio[1835]: Jack: Clock source : system clock via clock_gettime
nov. 11 12:37:59 terence-arch pulseaudio[1835]: Jack: JackLinuxFutex::Connect name = jack_sem.1000_default_PulseAudio JACK Sink
nov. 11 12:37:59 terence-arch pulseaudio[1835]: Jack: JackClient::SetupDriverSync driver sem in flush mode

@terencode
Copy link

terencode commented Nov 11, 2019

After more investigation, no matter what rlimit-rtprio or realtime-priority is set to, If jack realtime priority is > 10 it will fail. However, if jack priority <= 10 it will always work.

@imaami
Copy link
Contributor

imaami commented Nov 13, 2019

@terencode Can you please try with this branch?

@imaami
Copy link
Contributor

imaami commented Nov 13, 2019

@terencode After trying to reproduce your problem I can only come to the conclusion that you have something wrong with your configuration. Without any changes to jackd2 master I can only reproduce if I comment out rlimit-rtprio = 99 in /etc/pulse/daemon.conf. If I re-enable it everything works without any jack2 patching. (And my test branch from the previous comment doesn't fix it when rlimit-rtprio is disabled.)

Are you absolutely sure that you've enabled realtime capabilities for your user? Is the realtime group actually the correct group for your setup? How about your jackdbus settings, what's the realtime priority there?

@falkTX
Copy link
Member

falkTX commented Nov 13, 2019

Please note that under GNOME, which uses systemd user stuff, the PAM files are ignored.
There was a ticket a few days ago that mentioned it, cant find it now, but conclusion was to not start jackd over a terminal, but via qjackctl DBus mode.
For users of GNOME we have to create a new file similar to limits.conf, but in a location specific to systemd

@imaami
Copy link
Contributor

imaami commented Nov 13, 2019

Please note that under GNOME, which uses systemd user stuff, the PAM files are ignored.
There was a ticket a few days ago that mentioned it, cant find it now, but conclusion was to not start jackd over a terminal, but via qjackctl DBus mode.
For users of GNOME we have to create a new file similar to limits.conf, but in a location specific to systemd

Oh boy, dealing with systemd sure does occasionally feel like whatever the opposite of fun is.

@terencode How do you start jackdbus and pulseaudio? In which order? Where from? Automatically? Manually?

@terencode
Copy link

@imaami pulseaudio is started automatically by gnome using a systemd user unit and I manually start Jack with Cadence which uses the dbus implementation.

@terencode
Copy link

terencode commented Nov 13, 2019

Aaaaaand I figured out my stupid mistake: I had a ~/.pulse/daemon.conf lying around which did not include /etc/pulse/daemon.conf and as I saw after some hours spent looking at pulseaudio source code, it looks for a local file first and if it finds one, it doesn't try to read the global file. If you want to have your local file with only some settings while keeping the others set by the global one, you need to add .include /etc/pulse/daemon.conf at the beginning of the file...

@falkTX I think we can finally close this issue.

@falkTX
Copy link
Member

falkTX commented Nov 13, 2019

ok if you say so

@falkTX falkTX closed this as completed Nov 13, 2019
@codecollider
Copy link

Hi,

I'm getting the same error message with Cadence in Debian 10

Apr 24 20:30:28 marco pulseaudio[3256]: W: [pulseaudio] module-jack-sink.c: JACK error >Cannot use real-time scheduling (RR/75)(1: Die Operation ist nicht erlaubt)< Apr 24 20:30:28 marco pulseaudio[3256]: W: [pulseaudio] module-jack-sink.c: JACK error >JackClient::AcquireSelfRealTime error< Apr 24 20:30:29 marco pulseaudio[3256]: W: [pulseaudio] module-jack-source.c: JACK error >Cannot use real-time scheduling (RR/75)(1: Die Operation ist nicht erlaubt)< Apr 24 20:30:29 marco pulseaudio[3256]: W: [pulseaudio] module-jack-source.c: JACK error >JackClient::AcquireSelfRealTime error<

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

8 participants