Re: [LAD] Mackie Onyx 1640i: Long run playback results in xrun and hang.

[AreYouLoco? <areyouloco@paranoici.org>]

So the problem was pulseaudio hanging and not respawning because it cannot handle realtime priorities.

On September 13, 2021 11:36:59 AM UTC, AreYouLoco? <areyouloco@paranoici.org> wrote:
>I am going to recompile the kernel with options mentioned here:
>
>https://www.alsa-project.org/main/index.php/XRUN_Debug
>
>And try to debug why the xrun appears.
>
>I also checked with buffer size 1024 and exaclty one xrun and then hang repeats.
>
>On 9/13/21 12:23 PM, AreYouLoco? wrote:
>> Hi,
>> 
>> I am using custom build real-time kernel 5.12.2-rt3-fw. JACK with ALSA
>> backend on Mackie Onyx 1640i.
>> Lenovo Thinkpad T420 with FireWire. Debian Bullseye (11.0 - stable)
>> JACKD version 1.9.17.
>> I am using 512 samples 3 periods @48kHz.
>> 
>> The problem is that long run playback only around 1h (but the time
>> differs), result in
>> XRUN detected by JACK logs and the whole audio stops. So I have to
>> restart JACK in order to make it work.
>> DMESG is silent about that issue. But sometimes I get:
>> 
>> snd_oxfw fw1.0: Detect discontinuity of CIP: E8 00
>> And different hex values there.
>> 
>> Here is interesting part from the log:
>> 
>> Sun Sep 12 22:10:12 2021: Jack: JackRequest::Notification
>> Sun Sep 12 22:10:12 2021: Jack: **** alsa_pcm: xrun of at least 0.027 msecs
>> Sun Sep 12 22:10:12 2021: Jack: Repreparing capture
>> Sun Sep 12 22:10:12 2021: Jack: Repreparing playback
>> Sun Sep 12 22:10:12 2021: Jack: ALSA XRun wait_status = 0
>> Sun Sep 12 22:10:12 2021: Jack: JackEngine::ClientNotify: no callback
>> for notification = 3
>> Sun Sep 12 22:10:12 2021: Jack: JackEngine::ClientNotify: no callback
>> for notification = 3
>> Sun Sep 12 22:10:12 2021: Jack: JackClient::ClientNotify ref = 2 name =
>> dbusapi notify = 3
>> Sun Sep 12 22:10:12 2021: Jack: JackClient::kXRunCallback
>> Sun Sep 12 22:10:12 2021: Jack: JackEngine::ClientNotify: no callback
>> for notification = 3
>> Sun Sep 12 22:10:12 2021: Jack: JackEngine::ClientNotify: no callback
>> for notification = 3
>> Sun Sep 12 22:10:12 2021: Jack: JackEngine::ClientNotify: no callback
>> for notification = 3
>> Sun Sep 12 22:10:12 2021: Jack: JackEngine::ClientNotify: no callback
>> for notification = 3
>> Sun Sep 12 22:10:28 2021: ERROR: ALSA: poll time out, polled for
>> 15998655 usecs, Retrying with a recovery, retry cnt = 1
>> Sun Sep 12 22:10:44 2021: ERROR: ALSA: poll time out, polled for
>> 15998654 usecs, Retrying with a recovery, retry cnt = 2
>> Sun Sep 12 22:11:00 2021: ERROR: ALSA: poll time out, polled for
>> 15998659 usecs, Retrying with a recovery, retry cnt = 3
>> Sun Sep 12 22:11:16 2021: ERROR: ALSA: poll time out, polled for
>> 15998649 usecs, Retrying with a recovery, retry cnt = 4
>> 
>> Anyone have idea what might be the cause of this XRUN? Or how to debug that?
>> 
>> Its reproducible on my setup. Another log catched the same issue:
>> 
>> Sun Sep 12 16:50:44 2021: Jack: **** alsa_pcm: xrun of at least 0.030 msecs
>> Sun Sep 12 16:50:44 2021: Jack: Repreparing capture
>> Sun Sep 12 16:50:44 2021: Jack: Repreparing playback
>> Sun Sep 12 16:50:44 2021: Jack: ALSA XRun wait_status = 0
>> Sun Sep 12 16:50:44 2021: Jack: JackRequest::Notification
>> Sun Sep 12 16:50:44 2021: Jack: JackEngine::ClientNotify: no callback
>> for notification = 3
>> Sun Sep 12 16:50:44 2021: Jack: JackEngine::ClientNotify: no callback
>> for notification = 3
>> Sun Sep 12 16:50:44 2021: Jack: JackClient::ClientNotify ref = 2 name =
>> dbusapi notify = 3
>> Sun Sep 12 16:50:44 2021: Jack: JackClient::kXRunCallback
>> Sun Sep 12 16:50:44 2021: Jack: JackEngine::ClientNotify: no callback
>> for notification = 3
>> Sun Sep 12 16:50:44 2021: Jack: JackEngine::ClientNotify: no callback
>> for notification = 3
>> Sun Sep 12 16:50:44 2021: Jack: JackEngine::ClientNotify: no callback
>> for notification = 3
>> Sun Sep 12 16:50:44 2021: Jack: JackEngine::ClientNotify: no callback
>> for notification = 3
>> Sun Sep 12 16:51:00 2021: ERROR: ALSA: poll time out, polled for
>> 15998366 usecs, Retrying with a recovery, retry cnt = 1
>> Sun Sep 12 16:51:16 2021: ERROR: ALSA: poll time out, polled for
>> 15998353 usecs, Retrying with a recovery, retry cnt = 2
>> Sun Sep 12 16:51:32 2021: ERROR: ALSA: poll time out, polled for
>> 15998352 usecs, Retrying with a recovery, retry cnt = 3
>> Sun Sep 12 16:51:48 2021: ERROR: ALSA: poll time out, polled for
>> 15998367 usecs, Retrying with a recovery, retry cnt = 4
>> Sun Sep 12 16:52:04 2021: ERROR: ALSA: poll time out, polled for
>> 15998353 usecs, Retrying with a recovery, retry cnt = 5
>> Sun Sep 12 16:52:20 2021: ERROR: ALSA: poll time out, polled for
>> 15998371 usecs, Reached max retry cnt = 5, Exiting
>> Sun Sep 12 16:52:20 2021: ERROR: JackAudioDriver::ProcessAsync: read
>> error, stopping...
>> Sun Sep 12 16:52:20 2021: Jack: JackPosixThread::ThreadHandler : exit
>> 
>> I am willing to provide additional info.
>> 
>> Thank you in advance,
>> 
>> AreYouLoco?
>> _______________________________________________
>> Linux-audio-dev mailing list
>> Linux-audio-dev@lists.linuxaudio.org
>> https://lists.linuxaudio.org/listinfo/linux-audio-dev
>