Re: snd-usb: "delay: estimated 0, actual 352"

[Daniel Mack <zonque@gmail.com>]

On 06.09.2012 09:35, Takashi Iwai wrote:
> At Thu, 6 Sep 2012 09:17:57 +0200,
> Markus Trippelsdorf wrote:
>>
>> On 2012.09.06 at 09:08 +0200, Daniel Mack wrote:
>>> On 06.09.2012 08:53, Markus Trippelsdorf wrote:
>>>> On 2012.09.06 at 08:48 +0200, Takashi Iwai wrote:
>>>>> At Thu, 06 Sep 2012 08:33:30 +0200,
>>>>> Daniel Mack wrote:
>>>>>>
>>>>>> On 06.09.2012 08:02, Markus Trippelsdorf wrote:
>>>>>>> On 2012.09.04 at 16:40 +0200, Takashi Iwai wrote:
>>>>>>>> ----------------------------------------------------------------
>>>>>>>> Sound fixes for 3.6-rc5
>>>>>>>>
>>>>>>>> There are nothing scaring, contains only small fixes for HD-audio and
>>>>>>>> USB-audio:
>>>>>>>> - EPSS regression fix and GPIO fix for HD-audio IDT codecs
>>>>>>>> - A series of USB-audio regression fixes that are found since 3.5 kernel
>>>>>>>>
>>>>>>>> ----------------------------------------------------------------
>>>>>>>> Daniel Mack (4):
>>>>>>>>       ALSA: snd-usb: Fix URB cancellation at stream start
>>>>>>>>       ALSA: snd-usb: restore delay information
>>>>>>>         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 
>>>>>>> The commit fbcfbf5f above causes the following lines to be printed
>>>>>>> whenever I start a new song:
>>>>>>
>>>>>> Copied Pierre-Louis Bossart - he wrote the code in 294c4fb8 which this
>>>>>> patch (fbcfbf5f) brings back now.
>>>>>>
>>>>>>> delay: estimated 0, actual 352
>>>>>>> delay: estimated 353, actual 705
>>>>>>>
>>>>>>> (44.1 * 8 = 352.8)
>>>>>>>
>>>>>>> This happens with an USB-DAC that identifies itself as "C-Media USB
>>>>>>> Headphone Set".
>>>>>>
>>>>>> And you didn't you see these lines with 3.4?
>>>>>
>>>>> Maybe the difference of start condition?
>>>>>
>>>>> Markus, does the patch below fix anything?
>>>>
>>>> Unfortunately no.
>>>> However reverting the following fixes the problem:
>>>>
>>>> commit 245baf983cc39524cce39c24d01b276e6e653c9e
>>>> Author: Daniel Mack <zonque@gmail.com>
>>>> Date:   Thu Aug 30 18:52:30 2012 +0200
>>>>
>>>>     ALSA: snd-usb: fix calls to next_packet_size
>>>>
>>>
>>> No, this one certainly fixes a problem and does the right thing by
>>> restoring the original code.
>>>
>>> If you wouldn't state that you didn't see the same effect with 3.4(!),
>>> before the refactoring done in 3.5, I would believe the device is simply
>>> slightly off in its feedback rate and the tighter delay code complains
>>> about it while compensating, just as it did before.
>>>
>>> Are there any more than these two lines? And is audio working at all? Is
>>> it distorted in any way?
>>
>> There are only these two lines (printed whenever sound starts). Audio is
>> working just fine with no distortions.
>>
>> I did see similar lines before when the system load was very high
>> (happend during "make check" when building glibc).
>>
>> Here is what Pierre-Louis wrote in November 2011:
>>
>> »This was supposed to be an informational message, I thought it was only
>> enabled for debug. Regular users don't really need to know.«
> 
> I guess the problem is that the new endpoint scheme doesn't count the
> last_delay update unless the stream is triggered.  In the old code,
> retire_playback_urb is always called even before the trigger(START) is
> set.  And, there retire_playback_urb() does nothing but updating the
> delay information.
> 
> In the new code, retire_playback_urb is set only at
> snd_usb_substream_playback_trigger().  Thus at the very first shot,
> the delay account got confused.

In that case, I'd say we can also safely remove the debug output then.
Let's wait for Pierre-Louis' judgement here.


Daniel