Jackdbus and pulse

[David Henningsson]

On 01/10/2013 07:54 AM, Len Ovens wrote:
>
> On Wed, January 9, 2013 7:28 pm, David Henningsson wrote:
>> On 01/10/2013 12:46 AM, Len Ovens wrote:
>
>>> I have played around with this and there is a hack that will work. This
>>> is
>>> not a fix. When setting up qjackctl, there is a tab called "Options". On
>>> that panel there is a line with "Execute script on Startup". If this is
>>> enabled and the line:
>>>
>>> pasuspender sleep 5 &
>>
>> Interesting; I didn't think this would work, it probably shouldn't -
>> pasuspender should suspend all sinks, including the JACK sink.
>>
>> It must be because the JACK sink is created *after* pasuspender starts,
>> would be the reason why it is not suspended properly.
>
> That is the pre-start script in qjackctl.

Which should be removed/changed, I talked to Kaj about this on IRC a few 
days ago.

> The word devices caught my eye. It seemed to mean physical devices not
> just backends. Anyway I figured once jack had the device I could unsuspend
> pulse and because jack already had it, pulse would not be able to take it
> back. That seemed to be true and pulse seemed to feel jack-sink was the
> best option to stream audio to. That is why I felt the sleep option should
> work fine.

Ah; yes, that's true, pasuspender just runs for a tiny while, not during 
the entire jackd process.

>>> know if pasuspender uses dbus to tell
>>> PA to release HW devices?
>>
>> It uses PA's native protocol (which in turn uses unix sockets for
>> communication, and SHM for memory tranfers).
>
> Hmm, ok I can't conclude anything from that then.
>
>> To fix it in the right way you need to figure out why this happens in
>> the first place - I mean, it could be either one of these three:
>>
>> 1) PulseAudio does not release the device before answering on dbus
>> 2) Jackd2 does not wait for dbus answer before opening the device
>> 3) The kernel (or alsa-lib) does not release the device properly before
>> returning from snd_pcm_close.
>
> It looks like ... 4)

Thanks for looking into it.

> Something interesting happens in the jack logfile, The time stamps are not
> in order. The logging that qjackctl captures seems to come from different
> places (different colours too).
>
> Here is a section of the log where it fails:
> (my comments are indented)
>
> 17:53:18.689 D-BUS: JACK server could not be started. Sorry
>      This looks like the first line, but it is not.
>      D-BUS was free to write logs sooner thats all.
>
>      Now we have quite a normal jack startup.
> Wed Jan  9 17:53:17 2013: Starting jack server...

If you actually have two instances of jackdbus, shouldn't you have two 
rows of "Starting jack server..." too?

> Wed Jan  9 17:53:18 2013: JACK server starting in realtime mode with
> priority 10
> Wed Jan  9 17:53:18 2013: control device hw:1
> Wed Jan  9 17:53:18 2013: control device hw:1
> Wed Jan  9 17:53:18 2013: Acquired audio card Audio1
>      Hmm, we just aquired hw:1

"Audio1" likely refers to the dbus reservation, whereas "hw:1" refers to 
the kernel object.

"hw:1" is translated by alsa-lib into /dev/snd/pcmC1D0p (playback), 
/dev/snd/pcmC1D0c (capture), or /dev/snd/controlC1 (mixer). The mixer 
can be opened by several apps simultaneously, but playback and capture 
are for one app at a time.

> Wed Jan  9 17:53:18 2013: creating alsa driver ...
> hw:1|hw:1|64|2|48000|0|0|nomon|swmeter|-|32bit
> Wed Jan  9 17:53:18 2013: control device hw:1
>      Up till here it looked good
>
>      Then (no time stamp, I assume this means direct error output from
>      Qjackctl as this is the same output I see if I use jack_control.
> Cannot connect to server socket err = No such file or directory
> Cannot connect to server request channel
> jack server is not running or cannot be started
>      It was running how did it stop?
>
>      Now this looks like a failed start up... device in use. But, jack was
>      Already able to acquire it.
> Wed Jan  9 17:53:18 2013: ERROR:
> ATTENTION: The playback device "hw:1" is already in use. Please stop the
> application using it and run JACK again

Again notice the difference between "Audio1" and "hw:1".

It would be interesting to know "sudo fuser -v /dev/snd/pcm*" at exactly 
this point in time, because it should be unused.

> Wed Jan  9 17:53:18 2013: ERROR: Cannot initialize driver
> Wed Jan  9 17:53:18 2013: ERROR: JackServer::Open failed with -1
> Wed Jan  9 17:53:18 2013: ERROR: Failed to open server
> Wed Jan  9 17:53:19 2013: Saving settings to
> "/home/joe/.config/jack/conf.xml" ...
> 17:53:23.992 Could not connect to JACK server as client. - Overall
> operation failed. - Unable to connect to server. Please check the messages
> window for more info.
> Cannot connect to server socket err = No such file or directory
> Cannot connect to server request channel
> jack server is not running or cannot be started
>
> Ok, this is what seems to happen. This is my hypothesis:
> - Qjackctl sends a message via DBUS to start jack
> - Jack starts and asks for the device.
> - pulse gives the device.
> - jack gets it.
> - DBUS (on it's own or at the asking of qjackctl) checks that jack is
> running.
> - Jack is busy getting started and does not respond (or not soon enough).
> - DBUS does what it normally does when it can't contact a service and
> starts jackdbus (again)
> - Jack is already (still) running and has the device
> - the new jack instance tries to get the device and fails.
> - Anything that wants to talk to jack gets the address from DBUS of the
> new jack instance and fails or has DBUS try to start a new instance which
> fails.
>
> I'm sure I don't have it quite right... And I think we have new versions
> of _all_ the software since it worked. (Pulse, Jack (patch anyway), DBUS,
> Qjackctl, jack_control (bug fix)) <Len is not absolutely sure about
> qjackctl>
>
> My question is what happens to the first instance of jackdbus, Does it get
> confused? go zombie? Maybe there is only one instance of jack but when It
> gets the second DBUS signal to start, it tries to reaquire the port it
> already has.
>
> I'm not smart enough to figure it out, it would be nice if the log file
> included PIDs.
>



-- 
David Henningsson, Canonical Ltd.
https://launchpad.net/~diwic