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

[Christopher White <c.white@pulseforce.com>]

On 11/10/11 2:17 PM, Wu Fengguang wrote:
> 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

Nice find! It does seem likely since the ELD read worked right after 
that. Hmm. I am not familiar with the event order for the Intel 
hardware, and what's calling your edid_to_eld code, etc. Is it possible 
to move the EDID read call to after the DPMS state is ready?