Re: [PATCH v5] drm/i915: pass ELD to HDMI/DP audio driver

[Wu Fengguang <fengguang.wu@intel.com>]

On Thu, Nov 10, 2011 at 09:01:24PM +0800, Christopher White wrote:
> On 11/10/11 1:56 PM, Wu Fengguang wrote:
> > On Thu, Nov 10, 2011 at 07:50:11PM +0800, Christopher White wrote:
> >> On 11/10/11 12:22 PM, Takashi Iwai wrote:
> >>> At Thu, 10 Nov 2011 12:00:53 +0100,
> >>> Christopher White wrote:
> >>>> On 11/10/11 9:55 AM, Christopher White wrote:
> >>>>> On 11/10/11 8:55 AM, Wu Fengguang wrote:
> >>>>>> On Thu, Nov 10, 2011 at 03:33:50PM +0800, Wu Fengguang wrote:
> >>>>>>> Wow I reproduced the bug and got a very interesting dmesg:
> >>>>>>>
> >>>>>>> gfx =>           [ 4561.287980] [drm:intel_write_eld], ELD on
> >>>>>>> [CONNECTOR:12:HDMI-A-2], [ENCODER:11:TMDS-11]
> >>>>>>> gfx =>           [ 4561.291730] [drm:ironlake_write_eld], ELD on pipe B
> >>>>>>> gfx =>           [ 4561.293804] [drm:ironlake_write_eld], Audio
> >>>>>>> directed to unknown port
> >>>>>>> gfx =>           [ 4561.295273] [drm:ironlake_write_eld],
> >>>>>>>          alsa =>    [ 4561.295486] HDMI hot plug event: Codec=3 Pin=6
> >>>>>>> Presence_Detect=1 ELD_Valid=0
> >>>>>>>          alsa =>    [ 4561.295564] HDMI status: Codec=3 Pin=6
> >>>>>>> Presence_Detect=1 ELD_Valid=0
> >>>>>>> gfx =>           [ 4561.300020] ELD size 13
> >>>>>>>          alsa =>    [ 4561.300697] HDMI hot plug event: Codec=3 Pin=6
> >>>>>>> Presence_Detect=1 ELD_Valid=1
> >>>>>>>          alsa =>    [ 4561.303322] HDMI status: Codec=3 Pin=6
> >>>>>>> Presence_Detect=1 ELD_Valid=1
> >>>>>>>          alsa =>    [ 4561.311120] ALSA hda_eld.c:259 HDMI: Unknown ELD
> >>>>>>> version 0
> >>>>>>>
> >>>>>>> Hey the two parts are interleaved!
> >>>>>>>
> >>>>>>> But still it should work all fine, since the gfx driver does
> >>>>>>>
> >>>>>>>            set ELD_Valid = 0
> >>>>>>>            write ELD
> >>>>>>>            set ELD_Valid = 1
> >>>>>>>
> >>>>>>> So the audio driver would read the correct ELD unless the ELD content
> >>>>>>> and flag writes are somehow _reordered_ underneath. Or the ELD content
> >>>>>>> writes take some time to take effect?
> >>>>>> Just confirmed that adding 1s delay can fix it!
> >>>>>>
> >>>>>> New dmesg is:
> >>>>>>
> >>>>>> [   48.564923] [drm:drm_crtc_helper_set_mode], [ENCODER:11:TMDS-11]
> >>>>>> set [MODE:34:]
> >>>>>> [   48.567481] [drm:intel_hdmi_mode_set], Enabling HDMI audio on pipe B
> >>>>>> [   48.568975] [drm:intel_write_eld], ELD on [CONNECTOR:12:HDMI-A-2],
> >>>>>> [ENCODER:11:TMDS-11]
> >>>>>> [   48.571728] [drm:ironlake_write_eld], ELD on pipe B
> >>>>>> [   48.572882] [drm:ironlake_write_eld], Audio directed to unknown port
> >>>>>> [   48.575252] [drm:ironlake_write_eld],
> >>>>>> [   48.575400] HDMI hot plug event: Codec=3 Pin=6 Presence_Detect=1
> >>>>>> ELD_Valid=0
> >>>>>> [   48.575487] HDMI status: Codec=3 Pin=6 Presence_Detect=1 ELD_Valid=0
> >>>>>> [   48.580116] ELD size 13
> >>>>>> [   48.580795] HDMI hot plug event: Codec=3 Pin=6 Presence_Detect=1
> >>>>>> ELD_Valid=1
> >>>>>> [   48.583340] HDMI status: Codec=3 Pin=6 Presence_Detect=1 ELD_Valid=1
> >>>>>> [   48.632514] [drm:intel_wait_for_vblank], vblank wait timed out
> >>>>>> [   48.685322] [drm:intel_wait_for_vblank], vblank wait timed out
> >>>>>> [   48.687438] [drm:ironlake_update_wm], FIFO watermarks For pipe A -
> >>>>>> plane 5, cursor: 6
> >>>>>> [   48.687438] [drm:ironlake_update_wm], FIFO watermarks For pipe A -
> >>>>>> plane 5, cursor: 6
> >>>>>> [   48.690106] [drm:ironlake_update_wm], FIFO watermarks For pipe B -
> >>>>>> plane 42, cursor: 6
> >>>>>> [   48.745204] [drm:intel_wait_for_vblank], vblank wait timed out
> >>>>>> [   48.798035] [drm:intel_wait_for_vblank], vblank wait timed out
> >>>>>> [   48.799633] [drm:ironlake_fdi_link_train], FDI_RX_IIR 0x100
> >>>>>> [   48.802686] [drm:ironlake_fdi_link_train], FDI train 1 done.
> >>>>>> [   48.805103] [drm:ironlake_fdi_link_train], FDI_RX_IIR 0x600
> >>>>>> [   48.807246] [drm:ironlake_fdi_link_train], FDI train 2 done.
> >>>>>> [   48.809426] [drm:ironlake_fdi_link_train], FDI train done
> >>>>>> [   48.813960] [drm:intel_update_fbc],
> >>>>>> [   48.814782] [drm:drm_crtc_helper_set_config], Setting connector
> >>>>>> DPMS state to on
> >>>>>> [   48.818093] [drm:drm_crtc_helper_set_config],
> >>>>>> [CONNECTOR:12:HDMI-A-2] set DPMS on
> >>>>>> [   48.828633] [drm:intel_prepare_page_flip], preparing flip with no
> >>>>>> unpin work?
> >>>>>> [   49.618962] HDMI: detected monitor RX-V1800 at connection type HDMI
> >>>>>> [   49.621013] HDMI: available speakers: FL/FR LFE FC RL/RR RC RLC/RRC
> >>>>>> [   49.622304] HDMI: supports coding type LPCM: channels = 2, rates =
> >>>>>> 32000 44100 48000 96000 176400 192000 384000, bits = 16 20 24
> >>>>>> [   49.625069] HDMI: supports coding type LPCM: channels = 8, rates =
> >>>>>> 32000 44100 48000 96000 176400 192000 384000, bits = 16 20 24
> >>>>>> [   49.628535] HDMI: supports coding type AC-3: channels = 6, rates =
> >>>>>> 32000 44100 48000, max bitrate = 640000
> >>>>>> [   49.630810] HDMI: supports coding type DTS: channels = 7, rates =
> >>>>>> 32000 44100 48000 96000 176400, max bitrate = 1536000
> >>>>>> [   49.633148] HDMI: supports coding type DSD (One Bit Audio):
> >>>>>> channels = 6, rates = 44100
> >>>>>> [   49.635039] HDMI: supports coding type E-AC-3/DD+ (Dolby Digital
> >>>>>> Plus): channels = 8, rates = 44100 48000
> >>>>>> [   49.637130] HDMI: supports coding type MLP (Dolby TrueHD):
> >>>>>> channels = 8, rates = 48000 176400 384000
> >>>>>> [   49.639172] HDMI: supports coding type DTS-HD: channels = 8, rates
> >>>>>> = 48000 176400 384000
> >>>>>>
> >>>>>> Thanks,
> >>>>>> Fengguang
> >>>>> Wow, you were able to reproduce it! That's the best news ever. I will
> >>>>> be applying this patch and rebuilding now to see what happens. So it
> >>>>> was some sort of timing issue after all.
> >>>>>
> >>>>> Expect me to reply within 1h, but rebuild takes some time.
> >>>> I still had the old build directory and only had to rebuild one module
> >>>> which only took 5 minutes. The rest of the delay was me doing an hour of
> >>>> tests as well as being on a 45 minute phone call. Anyway, now the result:
> >>>>
> >>>> Success!
> >>>>
> >>>> So we know it's a timing issue somewhere. Wow, real progress and near a
> >>>> solution. Finally! The big question now is what causes the audio driver
> >>>> to read the ELD while it is empty, and why the 1 second delay fixes it.
> >>>>
> >>>> Look at speakertest.txt here. It's beautiful. ;-) Playing digital
> >>>> multichannel sound over the HDMI PCH bus, and I can hear every channel
> >>>> in their proper location on my speaker system. It's beautiful. I've
> >>>> waited for this moment since building this Linux HTPC back in April. ;-)
> >>>> (I'm an astonishingly patient man hehe).
> >>>>
> >>>> Now as for why we needed a 1 second delay, any ideas? Could it be that
> >>>> the audio driver was reading the ELD while it wasn't written to the
> >>>> register yet?
> >>> Maybe not necessarily 1 second.  It could do some loop with a small
> >>> delay until it reads zero-size?  Or if it really can take long time
> >>> like 1 second, it'd be better to be a work to self-reschdule to do in
> >>> background, as it's called at the probing time and at each unsol
> >>> event.  Since radeon sends really zero-byte ELD when a DVI monitor
> >>> without audio is connected, stalling one second there is no good
> >>> choice.
> >>>
> >>> Hopefully this delay would fix the zero-size problem we are currently
> >>> working around in an ugly way (the comment mentions about ASUS P5E-VM
> >>> HDMI board), too.
> >>>
> >>>
> >>> thanks,
> >>>
> >>> Takashi
> >> Well yes obviously the 1 second delay is a temporary workaround until
> >> the real cause is found.
> > Yes it's a quick hack to confirm the idea. The initial try is 100ms
> > delay but it's not working. So I took a big jump ;-)
> >
> > I'll experiment with smaller values.
> >
> >> Something like what you suggested should be the
> >> final fix; a real loop that proceeds only when the data is ready (with a
> >> 1 second or so maximum loop time, to avoid infinite loop if data never
> >> becomes ready).
> > I definitely would like to know the root cause.  Does it simply need
> > some time to take effect, or have some explicit "ready to go" condition?
> >
> > It looks ridiculous the hardware provided "ELD valid" flag does not
> > guarantee the availability of new ELD content.
> >
> > The more confusing thing is, why it reads 0 at all? The i915 ELD code
> > will never reset or write zeros to the hardware ELD buffer.
> >
> > So maybe the hardware is in some state that is unable to provide the
> > real ELD content?
> That's my guess as well. I think the hardware may still be doing some 
> form of data negotiation with the HDMI display device at that stage, and 
> doesn't have the copy of the EDID+ELD buffer until a tiny bit later. 
> Possibly?

Look at the below dmesg. The ELD seem to available immediately after the DPMS
state setting..

> >> I don't think a background schedule would work, because the data needs
> >> to be available at boot BEFORE the audio layer loads. Otherwise ALSA
> >> (for example) would load while no data had yet been read into the ELD
> >> registers. If a background schedule is used, then GREAT care must be
> >> taken to make sure it finishes before the audio layer launches.
> > Maybe we can do with the simple sleep-and-retry if it only requires
> > 200ms delay? Anyway let me try work out the time first.
> Yeah. If you have time, do something that looks for ELD availability in 
> a loop with msleep(10) and count how many iterations it takes to see the 
> data. That'd be the most granular approach.

Got the delay - it's 72.986623-72.747632 = 239ms.

        [   72.739944] HDMI hot plug event: Codec=3 Pin=6 Presence_Detect=1 ELD_Valid=0
        [   72.742541] HDMI status: Codec=3 Pin=6 Presence_Detect=1 ELD_Valid=0
        [   72.745082] HDMI hot plug event: Codec=3 Pin=6 Presence_Detect=1 ELD_Valid=1
        [   72.747632] HDMI status: Codec=3 Pin=6 Presence_Detect=1 ELD_Valid=1
        [   72.794240] [drm:intel_wait_for_vblank], vblank wait timed out
        [   72.848099] [drm:intel_wait_for_vblank], vblank wait timed out
        [   72.850507] [drm:ironlake_update_wm], FIFO watermarks For pipe A - plane 5, cursor: 6
        [   72.853244] [drm:ironlake_update_wm], FIFO watermarks For pipe B - plane 42, cursor: 6
        [   72.907937] [drm:intel_wait_for_vblank], vblank wait timed out
        [   72.960790] [drm:intel_wait_for_vblank], vblank wait timed out
        [   72.962757] [drm:ironlake_fdi_link_train], FDI_RX_IIR 0x100
        [   72.964880] [drm:ironlake_fdi_link_train], FDI train 1 done.
        [   72.968341] [drm:ironlake_fdi_link_train], FDI_RX_IIR 0x600
        [   72.970274] [drm:ironlake_fdi_link_train], FDI train 2 done.
        [   72.972535] [drm:ironlake_fdi_link_train], FDI train done
        [   72.976751] [drm:intel_update_fbc], 
        [   72.977558] [drm:drm_crtc_helper_set_config], Setting connector DPMS state to on
==>     [   72.981550] [drm:drm_crtc_helper_set_config],        [CONNECTOR:12:HDMI-A-2] set DPMS on
        [   72.986623] HDMI: detected monitor RX-V1800 at connection type HDMI
        [   72.988260] HDMI: available speakers: FL/FR LFE FC RL/RR RC RLC/RRC

I wonder if the DPMS line has anything to do with the delay...

Thanks,
Fengguang