[alsa-devel] snd-usb: "delay: estimated 0, actual 352"

[Takashi Iwai]

At Thu, 06 Sep 2012 09:35:26 +0200,
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 at 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 short, a patch like below may fix the issue (note: completely
untested!)


Takashi

---

diff --git a/sound/usb/pcm.c b/sound/usb/pcm.c
index fd5e982..928a4f7 100644
--- a/sound/usb/pcm.c
+++ b/sound/usb/pcm.c
@@ -528,6 +528,9 @@ static int snd_usb_hw_free(struct snd_pcm_substream *substream)
 	return snd_pcm_lib_free_vmalloc_buffer(substream);
 }
 
+static void retire_playback_urb(struct snd_usb_substream *subs,
+				struct urb *urb);
+
 /*
  * prepare callback
  *
@@ -561,8 +564,10 @@ static int snd_usb_pcm_prepare(struct snd_pcm_substream *substream)
 
 	/* for playback, submit the URBs now; otherwise, the first hwptr_done
 	 * updates for all URBs would happen at the same time when starting */
-	if (subs->direction == SNDRV_PCM_STREAM_PLAYBACK)
+	if (subs->direction == SNDRV_PCM_STREAM_PLAYBACK) {
+		subs->data_endpoint->retire_data_urb = retire_playback_urb;
 		return start_endpoints(subs, 1);
+	}
 
 	return 0;
 }
@@ -1190,7 +1195,6 @@ static int snd_usb_substream_playback_trigger(struct snd_pcm_substream *substrea
 	case SNDRV_PCM_TRIGGER_START:
 	case SNDRV_PCM_TRIGGER_PAUSE_RELEASE:
 		subs->data_endpoint->prepare_data_urb = prepare_playback_urb;
-		subs->data_endpoint->retire_data_urb = retire_playback_urb;
 		subs->running = 1;
 		return 0;
 	case SNDRV_PCM_TRIGGER_STOP:
@@ -1199,7 +1203,6 @@ static int snd_usb_substream_playback_trigger(struct snd_pcm_substream *substrea
 		return 0;
 	case SNDRV_PCM_TRIGGER_PAUSE_PUSH:
 		subs->data_endpoint->prepare_data_urb = NULL;
-		subs->data_endpoint->retire_data_urb = NULL;
 		subs->running = 0;
 		return 0;
 	}