[pulseaudio-discuss] pulseaudio fails to start with kernel 4.11, caused by new snd_hdmi_lpe_audio module)

[Arun Raghavan]

On Tue, 21 Mar 2017, at 08:19 PM, Hans de Goede wrote:
> Hi,
> 
> On 21-03-17 10:04, Arun Raghavan wrote:
> >
> >
> > On Tue, 21 Mar 2017, at 02:26 PM, Hans de Goede wrote:
> >> Hi,
> >>
> >> On 21-03-17 08:54, Arun Raghavan wrote:
> >>> On Tue, 21 Mar 2017, at 11:10 AM, Takashi Iwai wrote:
> >>>> On Tue, 21 Mar 2017 00:09:22 +0100,
> >>>> Pierre-Louis Bossart wrote:
> >>>>>
> >>>>> On 3/20/17 4:52 AM, Takashi Iwai wrote:
> >>>>>> On Mon, 20 Mar 2017 12:42:58 +0100,
> >>>>>> Hans de Goede wrote:
> >>>>>>>
> >>>>>>> Hi,
> >>>>>>>
> >>>>>>> Lately I've been working on fixing various issues people
> >>>>>>> are having with baytrail / cherrytrail devices. One thing
> >>>>>>> I noticed when moving my testing / development to 4.11 is
> >>>>>>> that pulseaudio does not work (it aborts while starting)
> >>>>>>> this seemed to be caused by the new snd_hdmi_lpe_audio
> >>>>>>> module. If I blacklist that all is fine. Any idea what
> >>>>>>> is causing this ?
> >>>>>>
> >>>>>> I noticed it once, too, but I had no time to check further.
> >>>>>> More interestingly, PA works fine when LPE audio is the single driver
> >>>>>> (i.e. blacklist Intel SST instead), too.  So it's more likely a bug in
> >>>>>> PA.
> >>>>>>
> >>>>>> What happens when you modprobe LPE audio driver after starting the
> >>>>>> session?  If it kills PA, we can debug more easily :)
> >>>>>
> >>>>> I've seen this as well, I could get either one of the two but not
> >>>>> both, could this be due to the fact that one set of mixers is
> >>>>> configured with UCM and the other driver isn't configured by UCM?
> >>>>
> >>>> No idea, and I had still no time to check (still processing the
> >>>> pile of pending mails and other bugs :).  Let me add PA guys to Cc.
> >>>
> >>> Not sure if anyone here has the hardware and I haven't seen any
> >>> complaints either -- having a backtrace (or even location of the assert)
> >>> would be a good start.
> >>
> >> Ok, this is weird. Since you were asking for more info I tried to
> >> collect a backtrace / logs. But what is happening is that after
> >> the snd_hdmi_lpe_audio module loads, pulse does its thing and
> >> then exits with a message of "killed" in gdb / on the terminal
> >> from which I started it. I don't get a chance to get a backtrace
> >> in gdb ...  So this does feel like a kernel bug to me, normally
> >> this sort of "killed" behavior is seen on some kernel oopses...
> >>
> >> But dmesg is free of any oopses ?
> >>
> >> Anyways here is a log of pulseaudio -v first without the
> >> hdmi module and then the module gets probed. Where the log
> >> abruptly ends is where I got the "Killed" message on the
> >> terminal.
> >
> > That's the kernel killing of PA for exceeding RT limits (there's a patch
> > in the timers tip that'll now provide an error in dmesg).
> >
> > It sounds possible that there is some call to the ALSA API that we are
> > making that results in the driver blocking for long enough to exceed the
> > RT limit. You can verify this by setting 'realtime-scheduling = no' in
> > /etc/pulse/daemon.conf and then starting PA.
> >
> > If that works,
> 
> Yep that works, good call.
> 
> > perf will likely be able to show you what's blocking.
> 
> I'm not all that familiar with perf, can you provide me with
> a perf cmdline to start pulseaudio with which will generate a log
> file with the info you are looking for ?

I'm no perf expert myself, but I'd start with:

1. sudo perf sched record
2. Start PA in another tab
3. sudo perf sched latency > latency.txt

The latency report should show you at what time the maximum delay
occurred and how large it was.

Thinking about it, a simple 'perf record pulseaudio' and 'perf report'
might also tell you where CPU time was spent.

Cheers,
Arun