Re: BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

Re: BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Alan Stern]

On Wed, 17 Apr 2013, Joe Rayhawk wrote:

> Small buffer/period sizes on usb audio playback though UHCI works fine on v3.7 but causes audio discontinuities/delays on v3.8 and v3.9-rc7.
> 
> I've bisected the behavior down to
> 
>     c44b225077bb1fb25ed5cd5c4f226897b91bedd4
>     'UHCI: implement new semantics for URB_ISO_ASAP'
> 
> Tested on two UHCI hosts and three usb-audio devices, all from different vendors.

Can you provide a usbmon trace showing the problems?  And maybe also a 
similar trace made under a 3.7 kernel, where the problem doesn't occur?

Alan Stern

Re: [alsa-devel] BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Alan Stern]

On Wed, 17 Apr 2013, Joe Rayhawk wrote:

> Small buffer/period sizes on usb audio playback though UHCI works fine on v3.7 but causes audio discontinuities/delays on v3.8 and v3.9-rc7.
> 
> I've bisected the behavior down to
> 
>     c44b225077bb1fb25ed5cd5c4f226897b91bedd4
>     'UHCI: implement new semantics for URB_ISO_ASAP'
> 
> Tested on two UHCI hosts and three usb-audio devices, all from different vendors.

Can you provide a usbmon trace showing the problems?  And maybe also a 
similar trace made under a 3.7 kernel, where the problem doesn't occur?

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe alsa-devel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

_______________________________________________
Alsa-devel mailing list
Alsa-devel@alsa-project.org
http://mailman.alsa-project.org/mailman/listinfo/alsa-devel

Re: BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Joe Rayhawk]

[-- Attachment #1.1: Type: text/plain, Size: 13498 bytes --]

On Thu, Apr 18, 2013 at 12:42:00PM -0400, Alan Stern wrote:
> On Wed, 17 Apr 2013, Joe Rayhawk wrote:
> > Small buffer/period sizes on usb audio playback though UHCI works fine on v3.7 but causes audio discontinuities/delays on v3.8 and v3.9-rc7.
>
> Can you provide a usbmon trace showing the problems?  And maybe also a 
> similar trace made under a 3.7 kernel, where the problem doesn't occur?

root@richardiv:~# uname -a; cat /sys/kernel/debug/usb/usbmon/6u & perl -e 'print pack "H*", "00FF" x 2048' | aplay --period-size=48 -r 44100 -f S16_LE -c2 -D hw:1,0; kill %1
Linux richardiv 3.7-trunk-amd64 #1 SMP Debian 3.7.1-1~experimental.1 x86_64 GNU/Linux
[1] 4407
Playing raw data 'stdin' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
ffff880155fd2780 288949785 S Co:6:007:0 s 01 0b 0001 0001 0000 0
ffff880155fd2780 288951516 C Co:6:007:0 0 0
ffff88015593f3c0 288951743 S Co:6:007:0 s 22 01 0100 0001 0003 3 = 44ac00
ffff88015593f3c0 288952512 C Co:6:007:0 0 3 >
ffff88015593f3c0 288952551 S Ci:6:007:0 s a2 81 0100 0001 0003 3 <
ffff88015593f3c0 288953511 C Ci:6:007:0 0 3 = 44ac00
ffff8801549cc780 288953559 S Zo:6:007:1 -115:1:0 1 -18:0:176 176 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
ffff8801549cca80 288953569 S Zo:6:007:1 -115:1:0 1 -18:0:176 176 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
ffff8801549cc780 288964489 C Zo:6:007:1 0:1:217621:0 1 0:0:176 176 >
ffff8801549cc780 288964505 S Zo:6:007:1 -115:1:217621 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288965508 C Zo:6:007:1 0:1:217622:0 1 0:0:176 176 >
ffff8801549cca80 288965527 S Zo:6:007:1 -115:1:217622 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288966486 C Zo:6:007:1 0:1:217623:0 1 0:0:176 176 >
ffff8801549cc780 288966503 S Zo:6:007:1 -115:1:217623 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288967488 C Zo:6:007:1 0:1:217624:0 1 0:0:176 176 >
ffff8801549cca80 288967507 S Zo:6:007:1 -115:1:217624 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288968508 C Zo:6:007:1 0:1:217625:0 1 0:0:176 176 >
ffff8801549cc780 288968523 S Zo:6:007:1 -115:1:217625 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288969485 C Zo:6:007:1 0:1:217626:0 1 0:0:176 176 >
ffff8801549cca80 288969499 S Zo:6:007:1 -115:1:217626 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288970507 C Zo:6:007:1 0:1:217627:0 1 0:0:176 176 >
ffff8801549cc780 288970520 S Zo:6:007:1 -115:1:217627 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288971487 C Zo:6:007:1 0:1:217628:0 1 0:0:176 176 >
ffff8801549cca80 288971505 S Zo:6:007:1 -115:1:217628 1 -18:0:180 180 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288972491 C Zo:6:007:1 0:1:217629:0 1 0:0:176 176 >
ffff8801549cc780 288972504 S Zo:6:007:1 -115:1:217629 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288973485 C Zo:6:007:1 0:1:217630:0 1 0:0:180 180 >
ffff8801549cca80 288973499 S Zo:6:007:1 -115:1:217630 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288974490 C Zo:6:007:1 0:1:217631:0 1 0:0:176 176 >
ffff8801549cc780 288974505 S Zo:6:007:1 -115:1:217631 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288975485 C Zo:6:007:1 0:1:217632:0 1 0:0:176 176 >
ffff8801549cca80 288975502 S Zo:6:007:1 -115:1:217632 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288976491 C Zo:6:007:1 0:1:217633:0 1 0:0:176 176 >
ffff8801549cc780 288976501 S Zo:6:007:1 -115:1:217633 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288977485 C Zo:6:007:1 0:1:217634:0 1 0:0:176 176 >
ffff8801549cca80 288977503 S Zo:6:007:1 -115:1:217634 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288978491 C Zo:6:007:1 0:1:217635:0 1 0:0:176 176 >
ffff8801549cc780 288978506 S Zo:6:007:1 -115:1:217635 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288979481 C Zo:6:007:1 0:1:217636:0 1 0:0:176 176 >
ffff8801549cca80 288979489 S Zo:6:007:1 -115:1:217636 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288980484 C Zo:6:007:1 0:1:217637:0 1 0:0:176 176 >
ffff8801549cc780 288980493 S Zo:6:007:1 -115:1:217637 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288981481 C Zo:6:007:1 0:1:217638:0 1 0:0:176 176 >
ffff8801549cca80 288981490 S Zo:6:007:1 -115:1:217638 1 -18:0:180 180 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288982483 C Zo:6:007:1 0:1:217639:0 1 0:0:176 176 >
ffff8801549cc780 288982491 S Zo:6:007:1 -115:1:217639 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288983484 C Zo:6:007:1 0:1:217640:0 1 0:0:180 180 >
ffff8801549cca80 288983493 S Zo:6:007:1 -115:1:217640 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288984481 C Zo:6:007:1 0:1:217641:0 1 0:0:176 176 >
ffff8801549cc780 288984489 S Zo:6:007:1 -115:1:217641 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288985488 C Zo:6:007:1 0:1:217642:0 1 0:0:176 176 >
ffff8801549cca80 288985499 S Zo:6:007:1 -115:1:217642 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288986489 C Zo:6:007:1 0:1:217643:0 1 0:0:176 176 >
ffff8801549cc780 288986498 S Zo:6:007:1 -115:1:217643 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288987499 C Zo:6:007:1 0:1:217644:0 1 0:0:176 176 >
ffff8801549cca80 288987513 S Zo:6:007:1 -115:1:217644 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288988485 C Zo:6:007:1 -104:1:217645:0 1 0:0:176 176 >
ffff8801549cca80 288989499 C Zo:6:007:1 0:1:217646:0 1 0:0:176 176 >
ffff880150ffa9c0 288990672 S Co:6:007:0 s 01 0b 0000 0001 0000 0
ffff880150ffa9c0 288992510 C Co:6:007:0 0 0
root@richardiv:~# # Generated only opening and closing clicks

root@richardiv:~# uname -a; cat /sys/kernel/debug/usb/usbmon/4u & perl -e 'print pack "H*", "00FF" x 2048' | aplay --period-size=48 -r 44100 -f S16_LE -c2 -D hw:1,0; kill %1
Linux richardiv 3.8-trunk-amd64 #1 SMP Debian 3.8-1~experimental.1 x86_64 GNU/Linux
[1] 4702
Playing raw data 'stdin' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
ffff880144da0680 3864218837 S Co:4:002:0 s 01 0b 0001 0001 0000 0
ffff880144da0680 3864219942 C Co:4:002:0 0 0
ffff880153b6cd40 3864220177 S Co:4:002:0 s 22 01 0100 0001 0003 3 = 44ac00
ffff880153b6cd40 3864220943 C Co:4:002:0 0 3 >
ffff880153b6cd40 3864221002 S Ci:4:002:0 s a2 81 0100 0001 0003 3 <
ffff880153b6cd40 3864221940 C Ci:4:002:0 0 3 = 44ac00
ffff880143c80d80 3864222054 S Zo:4:002:1 -115:1:0 1 -18:0:176 176 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
ffff880143c80180 3864222066 S Zo:4:002:1 -115:1:0 1 -18:0:176 176 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
ffff880143c80d80 3864232940 C Zo:4:002:1 0:1:1057125:0 1 0:0:176 176 >
ffff880143c80d80 3864232956 S Zo:4:002:1 -115:1:1057125 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864233934 C Zo:4:002:1 0:1:1057126:0 1 0:0:176 176 >
ffff880143c80180 3864233955 S Zo:4:002:1 -115:1:1057126 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864235913 C Zo:4:002:1 0:1:1057128:0 1 0:0:176 176 >
ffff880143c80d80 3864235932 S Zo:4:002:1 -115:1:1057128 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864236910 C Zo:4:002:1 0:1:1057129:0 1 0:0:176 176 >
ffff880143c80180 3864236927 S Zo:4:002:1 -115:1:1057129 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864238939 C Zo:4:002:1 0:1:1057131:0 1 0:0:176 176 >
ffff880143c80d80 3864238959 S Zo:4:002:1 -115:1:1057131 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864239910 C Zo:4:002:1 0:1:1057132:0 1 0:0:176 176 >
ffff880143c80180 3864239926 S Zo:4:002:1 -115:1:1057132 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864241929 C Zo:4:002:1 0:1:1057134:0 1 0:0:176 176 >
ffff880143c80d80 3864241940 S Zo:4:002:1 -115:1:1057134 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864242905 C Zo:4:002:1 0:1:1057135:0 1 0:0:176 176 >
ffff880143c80180 3864242913 S Zo:4:002:1 -115:1:1057135 1 -18:0:180 180 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864244931 C Zo:4:002:1 0:1:1057137:0 1 0:0:176 176 >
ffff880143c80d80 3864244941 S Zo:4:002:1 -115:1:1057137 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864245929 C Zo:4:002:1 0:1:1057138:0 1 0:0:180 180 >
ffff880143c80180 3864245938 S Zo:4:002:1 -115:1:1057138 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864247913 C Zo:4:002:1 0:1:1057140:0 1 0:0:176 176 >
ffff880143c80d80 3864247933 S Zo:4:002:1 -115:1:1057140 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864248933 C Zo:4:002:1 0:1:1057141:0 1 0:0:176 176 >
ffff880143c80180 3864248945 S Zo:4:002:1 -115:1:1057141 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864250910 C Zo:4:002:1 0:1:1057143:0 1 0:0:176 176 >
ffff880143c80d80 3864250928 S Zo:4:002:1 -115:1:1057143 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864251930 C Zo:4:002:1 0:1:1057144:0 1 0:0:176 176 >
ffff880143c80180 3864251945 S Zo:4:002:1 -115:1:1057144 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864253910 C Zo:4:002:1 0:1:1057146:0 1 0:0:176 176 >
ffff880143c80d80 3864253930 S Zo:4:002:1 -115:1:1057146 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864254938 C Zo:4:002:1 0:1:1057147:0 1 0:0:176 176 >
ffff880143c80180 3864254948 S Zo:4:002:1 -115:1:1057147 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864256910 C Zo:4:002:1 0:1:1057149:0 1 0:0:176 176 >
ffff880143c80d80 3864256928 S Zo:4:002:1 -115:1:1057149 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864257909 C Zo:4:002:1 0:1:1057150:0 1 0:0:176 176 >
ffff880143c80180 3864257926 S Zo:4:002:1 -115:1:1057150 1 -18:0:180 180 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864259934 C Zo:4:002:1 0:1:1057152:0 1 0:0:176 176 >
ffff880143c80d80 3864259947 S Zo:4:002:1 -115:1:1057152 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864260930 C Zo:4:002:1 0:1:1057153:0 1 0:0:180 180 >
ffff880143c80180 3864260941 S Zo:4:002:1 -115:1:1057153 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864262909 C Zo:4:002:1 0:1:1057155:0 1 0:0:176 176 >
ffff880143c80d80 3864262927 S Zo:4:002:1 -115:1:1057155 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864263907 C Zo:4:002:1 0:1:1057156:0 1 0:0:176 176 >
ffff880143c80180 3864263924 S Zo:4:002:1 -115:1:1057156 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864265914 C Zo:4:002:1 0:1:1057158:0 1 0:0:176 176 >
ffff880143c80d80 3864265930 S Zo:4:002:1 -115:1:1057158 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864266931 C Zo:4:002:1 0:1:1057159:0 1 0:0:176 176 >
ffff880143c80180 3864266949 S Zo:4:002:1 -115:1:1057159 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864268912 C Zo:4:002:1 -104:1:1057161:1 1 -18:0:0 176 >
ffff880143c80180 3864269906 C Zo:4:002:1 0:1:1057162:0 1 0:0:176 176 >
ffff880154907ec0 3864273399 S Co:4:002:0 s 01 0b 0000 0001 0000 0
ffff880154907ec0 3864274911 C Co:4:002:0 0 0
root@richardiv:~# # generated tone due to high rate of discontinuities

Should I capture enumeration and setup, too?

[-- Attachment #1.2: Digital signature --]
[-- Type: application/pgp-signature, Size: 836 bytes --]

[-- Attachment #2: Type: text/plain, Size: 0 bytes --]

Re: [alsa-devel] BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Joe Rayhawk]

[-- Attachment #1.1: Type: text/plain, Size: 13498 bytes --]

On Thu, Apr 18, 2013 at 12:42:00PM -0400, Alan Stern wrote:
> On Wed, 17 Apr 2013, Joe Rayhawk wrote:
> > Small buffer/period sizes on usb audio playback though UHCI works fine on v3.7 but causes audio discontinuities/delays on v3.8 and v3.9-rc7.
>
> Can you provide a usbmon trace showing the problems?  And maybe also a 
> similar trace made under a 3.7 kernel, where the problem doesn't occur?

root@richardiv:~# uname -a; cat /sys/kernel/debug/usb/usbmon/6u & perl -e 'print pack "H*", "00FF" x 2048' | aplay --period-size=48 -r 44100 -f S16_LE -c2 -D hw:1,0; kill %1
Linux richardiv 3.7-trunk-amd64 #1 SMP Debian 3.7.1-1~experimental.1 x86_64 GNU/Linux
[1] 4407
Playing raw data 'stdin' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
ffff880155fd2780 288949785 S Co:6:007:0 s 01 0b 0001 0001 0000 0
ffff880155fd2780 288951516 C Co:6:007:0 0 0
ffff88015593f3c0 288951743 S Co:6:007:0 s 22 01 0100 0001 0003 3 = 44ac00
ffff88015593f3c0 288952512 C Co:6:007:0 0 3 >
ffff88015593f3c0 288952551 S Ci:6:007:0 s a2 81 0100 0001 0003 3 <
ffff88015593f3c0 288953511 C Ci:6:007:0 0 3 = 44ac00
ffff8801549cc780 288953559 S Zo:6:007:1 -115:1:0 1 -18:0:176 176 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
ffff8801549cca80 288953569 S Zo:6:007:1 -115:1:0 1 -18:0:176 176 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
ffff8801549cc780 288964489 C Zo:6:007:1 0:1:217621:0 1 0:0:176 176 >
ffff8801549cc780 288964505 S Zo:6:007:1 -115:1:217621 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288965508 C Zo:6:007:1 0:1:217622:0 1 0:0:176 176 >
ffff8801549cca80 288965527 S Zo:6:007:1 -115:1:217622 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288966486 C Zo:6:007:1 0:1:217623:0 1 0:0:176 176 >
ffff8801549cc780 288966503 S Zo:6:007:1 -115:1:217623 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288967488 C Zo:6:007:1 0:1:217624:0 1 0:0:176 176 >
ffff8801549cca80 288967507 S Zo:6:007:1 -115:1:217624 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288968508 C Zo:6:007:1 0:1:217625:0 1 0:0:176 176 >
ffff8801549cc780 288968523 S Zo:6:007:1 -115:1:217625 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288969485 C Zo:6:007:1 0:1:217626:0 1 0:0:176 176 >
ffff8801549cca80 288969499 S Zo:6:007:1 -115:1:217626 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288970507 C Zo:6:007:1 0:1:217627:0 1 0:0:176 176 >
ffff8801549cc780 288970520 S Zo:6:007:1 -115:1:217627 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288971487 C Zo:6:007:1 0:1:217628:0 1 0:0:176 176 >
ffff8801549cca80 288971505 S Zo:6:007:1 -115:1:217628 1 -18:0:180 180 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288972491 C Zo:6:007:1 0:1:217629:0 1 0:0:176 176 >
ffff8801549cc780 288972504 S Zo:6:007:1 -115:1:217629 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288973485 C Zo:6:007:1 0:1:217630:0 1 0:0:180 180 >
ffff8801549cca80 288973499 S Zo:6:007:1 -115:1:217630 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288974490 C Zo:6:007:1 0:1:217631:0 1 0:0:176 176 >
ffff8801549cc780 288974505 S Zo:6:007:1 -115:1:217631 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288975485 C Zo:6:007:1 0:1:217632:0 1 0:0:176 176 >
ffff8801549cca80 288975502 S Zo:6:007:1 -115:1:217632 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288976491 C Zo:6:007:1 0:1:217633:0 1 0:0:176 176 >
ffff8801549cc780 288976501 S Zo:6:007:1 -115:1:217633 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288977485 C Zo:6:007:1 0:1:217634:0 1 0:0:176 176 >
ffff8801549cca80 288977503 S Zo:6:007:1 -115:1:217634 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288978491 C Zo:6:007:1 0:1:217635:0 1 0:0:176 176 >
ffff8801549cc780 288978506 S Zo:6:007:1 -115:1:217635 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288979481 C Zo:6:007:1 0:1:217636:0 1 0:0:176 176 >
ffff8801549cca80 288979489 S Zo:6:007:1 -115:1:217636 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288980484 C Zo:6:007:1 0:1:217637:0 1 0:0:176 176 >
ffff8801549cc780 288980493 S Zo:6:007:1 -115:1:217637 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288981481 C Zo:6:007:1 0:1:217638:0 1 0:0:176 176 >
ffff8801549cca80 288981490 S Zo:6:007:1 -115:1:217638 1 -18:0:180 180 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288982483 C Zo:6:007:1 0:1:217639:0 1 0:0:176 176 >
ffff8801549cc780 288982491 S Zo:6:007:1 -115:1:217639 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288983484 C Zo:6:007:1 0:1:217640:0 1 0:0:180 180 >
ffff8801549cca80 288983493 S Zo:6:007:1 -115:1:217640 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288984481 C Zo:6:007:1 0:1:217641:0 1 0:0:176 176 >
ffff8801549cc780 288984489 S Zo:6:007:1 -115:1:217641 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288985488 C Zo:6:007:1 0:1:217642:0 1 0:0:176 176 >
ffff8801549cca80 288985499 S Zo:6:007:1 -115:1:217642 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288986489 C Zo:6:007:1 0:1:217643:0 1 0:0:176 176 >
ffff8801549cc780 288986498 S Zo:6:007:1 -115:1:217643 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cca80 288987499 C Zo:6:007:1 0:1:217644:0 1 0:0:176 176 >
ffff8801549cca80 288987513 S Zo:6:007:1 -115:1:217644 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801549cc780 288988485 C Zo:6:007:1 -104:1:217645:0 1 0:0:176 176 >
ffff8801549cca80 288989499 C Zo:6:007:1 0:1:217646:0 1 0:0:176 176 >
ffff880150ffa9c0 288990672 S Co:6:007:0 s 01 0b 0000 0001 0000 0
ffff880150ffa9c0 288992510 C Co:6:007:0 0 0
root@richardiv:~# # Generated only opening and closing clicks

root@richardiv:~# uname -a; cat /sys/kernel/debug/usb/usbmon/4u & perl -e 'print pack "H*", "00FF" x 2048' | aplay --period-size=48 -r 44100 -f S16_LE -c2 -D hw:1,0; kill %1
Linux richardiv 3.8-trunk-amd64 #1 SMP Debian 3.8-1~experimental.1 x86_64 GNU/Linux
[1] 4702
Playing raw data 'stdin' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
ffff880144da0680 3864218837 S Co:4:002:0 s 01 0b 0001 0001 0000 0
ffff880144da0680 3864219942 C Co:4:002:0 0 0
ffff880153b6cd40 3864220177 S Co:4:002:0 s 22 01 0100 0001 0003 3 = 44ac00
ffff880153b6cd40 3864220943 C Co:4:002:0 0 3 >
ffff880153b6cd40 3864221002 S Ci:4:002:0 s a2 81 0100 0001 0003 3 <
ffff880153b6cd40 3864221940 C Ci:4:002:0 0 3 = 44ac00
ffff880143c80d80 3864222054 S Zo:4:002:1 -115:1:0 1 -18:0:176 176 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
ffff880143c80180 3864222066 S Zo:4:002:1 -115:1:0 1 -18:0:176 176 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
ffff880143c80d80 3864232940 C Zo:4:002:1 0:1:1057125:0 1 0:0:176 176 >
ffff880143c80d80 3864232956 S Zo:4:002:1 -115:1:1057125 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864233934 C Zo:4:002:1 0:1:1057126:0 1 0:0:176 176 >
ffff880143c80180 3864233955 S Zo:4:002:1 -115:1:1057126 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864235913 C Zo:4:002:1 0:1:1057128:0 1 0:0:176 176 >
ffff880143c80d80 3864235932 S Zo:4:002:1 -115:1:1057128 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864236910 C Zo:4:002:1 0:1:1057129:0 1 0:0:176 176 >
ffff880143c80180 3864236927 S Zo:4:002:1 -115:1:1057129 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864238939 C Zo:4:002:1 0:1:1057131:0 1 0:0:176 176 >
ffff880143c80d80 3864238959 S Zo:4:002:1 -115:1:1057131 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864239910 C Zo:4:002:1 0:1:1057132:0 1 0:0:176 176 >
ffff880143c80180 3864239926 S Zo:4:002:1 -115:1:1057132 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864241929 C Zo:4:002:1 0:1:1057134:0 1 0:0:176 176 >
ffff880143c80d80 3864241940 S Zo:4:002:1 -115:1:1057134 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864242905 C Zo:4:002:1 0:1:1057135:0 1 0:0:176 176 >
ffff880143c80180 3864242913 S Zo:4:002:1 -115:1:1057135 1 -18:0:180 180 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864244931 C Zo:4:002:1 0:1:1057137:0 1 0:0:176 176 >
ffff880143c80d80 3864244941 S Zo:4:002:1 -115:1:1057137 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864245929 C Zo:4:002:1 0:1:1057138:0 1 0:0:180 180 >
ffff880143c80180 3864245938 S Zo:4:002:1 -115:1:1057138 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864247913 C Zo:4:002:1 0:1:1057140:0 1 0:0:176 176 >
ffff880143c80d80 3864247933 S Zo:4:002:1 -115:1:1057140 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864248933 C Zo:4:002:1 0:1:1057141:0 1 0:0:176 176 >
ffff880143c80180 3864248945 S Zo:4:002:1 -115:1:1057141 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864250910 C Zo:4:002:1 0:1:1057143:0 1 0:0:176 176 >
ffff880143c80d80 3864250928 S Zo:4:002:1 -115:1:1057143 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864251930 C Zo:4:002:1 0:1:1057144:0 1 0:0:176 176 >
ffff880143c80180 3864251945 S Zo:4:002:1 -115:1:1057144 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864253910 C Zo:4:002:1 0:1:1057146:0 1 0:0:176 176 >
ffff880143c80d80 3864253930 S Zo:4:002:1 -115:1:1057146 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864254938 C Zo:4:002:1 0:1:1057147:0 1 0:0:176 176 >
ffff880143c80180 3864254948 S Zo:4:002:1 -115:1:1057147 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864256910 C Zo:4:002:1 0:1:1057149:0 1 0:0:176 176 >
ffff880143c80d80 3864256928 S Zo:4:002:1 -115:1:1057149 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864257909 C Zo:4:002:1 0:1:1057150:0 1 0:0:176 176 >
ffff880143c80180 3864257926 S Zo:4:002:1 -115:1:1057150 1 -18:0:180 180 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864259934 C Zo:4:002:1 0:1:1057152:0 1 0:0:176 176 >
ffff880143c80d80 3864259947 S Zo:4:002:1 -115:1:1057152 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864260930 C Zo:4:002:1 0:1:1057153:0 1 0:0:180 180 >
ffff880143c80180 3864260941 S Zo:4:002:1 -115:1:1057153 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864262909 C Zo:4:002:1 0:1:1057155:0 1 0:0:176 176 >
ffff880143c80d80 3864262927 S Zo:4:002:1 -115:1:1057155 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864263907 C Zo:4:002:1 0:1:1057156:0 1 0:0:176 176 >
ffff880143c80180 3864263924 S Zo:4:002:1 -115:1:1057156 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864265914 C Zo:4:002:1 0:1:1057158:0 1 0:0:176 176 >
ffff880143c80d80 3864265930 S Zo:4:002:1 -115:1:1057158 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80180 3864266931 C Zo:4:002:1 0:1:1057159:0 1 0:0:176 176 >
ffff880143c80180 3864266949 S Zo:4:002:1 -115:1:1057159 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880143c80d80 3864268912 C Zo:4:002:1 -104:1:1057161:1 1 -18:0:0 176 >
ffff880143c80180 3864269906 C Zo:4:002:1 0:1:1057162:0 1 0:0:176 176 >
ffff880154907ec0 3864273399 S Co:4:002:0 s 01 0b 0000 0001 0000 0
ffff880154907ec0 3864274911 C Co:4:002:0 0 0
root@richardiv:~# # generated tone due to high rate of discontinuities

Should I capture enumeration and setup, too?

[-- Attachment #1.2: Digital signature --]
[-- Type: application/pgp-signature, Size: 836 bytes --]

[-- Attachment #2: Type: text/plain, Size: 160 bytes --]

_______________________________________________
Alsa-devel mailing list
Alsa-devel@alsa-project.org
http://mailman.alsa-project.org/mailman/listinfo/alsa-devel

Re: BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Alan Stern]

On Thu, 18 Apr 2013, Joe Rayhawk wrote:

> On Thu, Apr 18, 2013 at 12:42:00PM -0400, Alan Stern wrote:
> > On Wed, 17 Apr 2013, Joe Rayhawk wrote:
> > > Small buffer/period sizes on usb audio playback though UHCI works fine on v3.7 but causes audio discontinuities/delays on v3.8 and v3.9-rc7.
> >
> > Can you provide a usbmon trace showing the problems?  And maybe also a 
> > similar trace made under a 3.7 kernel, where the problem doesn't occur?
> 
> root@richardiv:~# uname -a; cat /sys/kernel/debug/usb/usbmon/6u & perl -e 'print pack "H*", "00FF" x 2048' | aplay --period-size=48 -r 44100 -f S16_LE -c2 -D hw:1,0; kill %1
> Linux richardiv 3.7-trunk-amd64 #1 SMP Debian 3.7.1-1~experimental.1 x86_64 GNU/Linux
> [1] 4407
> Playing raw data 'stdin' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo

I don't know exactly what that "--period-size=48" parameter is supposed
to accomplish.  The man page talks about time between interrupts, but
this doesn't seem to be related at all to what the usbmon trace shows.  
In this test, the audio driver ended up using two 1-ms buffers.

> ffff8801549cc780 288953559 S Zo:6:007:1 -115:1:0 1 -18:0:176 176 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
> ffff8801549cca80 288953569 S Zo:6:007:1 -115:1:0 1 -18:0:176 176 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000

Here the pipeline is started by writing two buffers of zeros.

> ffff8801549cc780 288964489 C Zo:6:007:1 0:1:217621:0 1 0:0:176 176 >
> ffff8801549cc780 288964505 S Zo:6:007:1 -115:1:217621 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff8801549cca80 288965508 C Zo:6:007:1 0:1:217622:0 1 0:0:176 176 >
> ffff8801549cca80 288965527 S Zo:6:007:1 -115:1:217622 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff

In the remainder, each time a buffer completes, a new one is
submitted.  This implies a latency of less than 1 ms.  Evidently that
works okay on your system, but it won't work everywhere.

> ffff8801549cc780 288966486 C Zo:6:007:1 0:1:217623:0 1 0:0:176 176 >
> ffff8801549cc780 288966503 S Zo:6:007:1 -115:1:217623 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff8801549cca80 288967488 C Zo:6:007:1 0:1:217624:0 1 0:0:176 176 >
> ffff8801549cca80 288967507 S Zo:6:007:1 -115:1:217624 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff8801549cc780 288968508 C Zo:6:007:1 0:1:217625:0 1 0:0:176 176 >
> ffff8801549cc780 288968523 S Zo:6:007:1 -115:1:217625 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff8801549cca80 288969485 C Zo:6:007:1 0:1:217626:0 1 0:0:176 176 >
> ffff8801549cca80 288969499 S Zo:6:007:1 -115:1:217626 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff8801549cc780 288970507 C Zo:6:007:1 0:1:217627:0 1 0:0:176 176 >
> ffff8801549cc780 288970520 S Zo:6:007:1 -115:1:217627 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff8801549cca80 288971487 C Zo:6:007:1 0:1:217628:0 1 0:0:176 176 >
...

I won't include the whole log.  It's worth noticing that the URB
completion lines (the lines with "C") show no -EXDEV (-18) errors, and
the frame numbers increase sequentially (217623, 217624, 217625,
...).  This is consistent with the sound being produced correctly.

> root@richardiv:~# # Generated only opening and closing clicks
> 
> root@richardiv:~# uname -a; cat /sys/kernel/debug/usb/usbmon/4u & perl -e 'print pack "H*", "00FF" x 2048' | aplay --period-size=48 -r 44100 -f S16_LE -c2 -D hw:1,0; kill %1
> Linux richardiv 3.8-trunk-amd64 #1 SMP Debian 3.8-1~experimental.1 x86_64 GNU/Linux

> ffff880143c80d80 3864232940 C Zo:4:002:1 0:1:1057125:0 1 0:0:176 176 >
> ffff880143c80d80 3864232956 S Zo:4:002:1 -115:1:1057125 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff880143c80180 3864233934 C Zo:4:002:1 0:1:1057126:0 1 0:0:176 176 >
> ffff880143c80180 3864233955 S Zo:4:002:1 -115:1:1057126 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff880143c80d80 3864235913 C Zo:4:002:1 0:1:1057128:0 1 0:0:176 176 >
> ffff880143c80d80 3864235932 S Zo:4:002:1 -115:1:1057128 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff880143c80180 3864236910 C Zo:4:002:1 0:1:1057129:0 1 0:0:176 176 >
> ffff880143c80180 3864236927 S Zo:4:002:1 -115:1:1057129 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff880143c80d80 3864238939 C Zo:4:002:1 0:1:1057131:0 1 0:0:176 176 >
...

This trace shows that the frame numbers do not increase sequentially:
1057125, 1057126, 1057128, 1057129, 1053131, ...  This is because the
new driver is a little more conservative than the old driver,
requiring latencies to be larger than 1 ms.  You can see this 
explicitly in one of the new lines added by the commit you found:

+		next = uhci->frame_number + 2;

That 2 is the minimum latency, in frames (one frame per ms).

Anyway, the solution is simple: The audio driver needs either to submit
buffers that are at least 2 ms long, or to use more than two buffers
(or both).  What the appropriate command parameters for aplay should
be, I can't tell you.

> Should I capture enumeration and setup, too?

No need.

Alan Stern

Re: [alsa-devel] BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Alan Stern]

On Thu, 18 Apr 2013, Joe Rayhawk wrote:

> On Thu, Apr 18, 2013 at 12:42:00PM -0400, Alan Stern wrote:
> > On Wed, 17 Apr 2013, Joe Rayhawk wrote:
> > > Small buffer/period sizes on usb audio playback though UHCI works fine on v3.7 but causes audio discontinuities/delays on v3.8 and v3.9-rc7.
> >
> > Can you provide a usbmon trace showing the problems?  And maybe also a 
> > similar trace made under a 3.7 kernel, where the problem doesn't occur?
> 
> root@richardiv:~# uname -a; cat /sys/kernel/debug/usb/usbmon/6u & perl -e 'print pack "H*", "00FF" x 2048' | aplay --period-size=48 -r 44100 -f S16_LE -c2 -D hw:1,0; kill %1
> Linux richardiv 3.7-trunk-amd64 #1 SMP Debian 3.7.1-1~experimental.1 x86_64 GNU/Linux
> [1] 4407
> Playing raw data 'stdin' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo

I don't know exactly what that "--period-size=48" parameter is supposed
to accomplish.  The man page talks about time between interrupts, but
this doesn't seem to be related at all to what the usbmon trace shows.  
In this test, the audio driver ended up using two 1-ms buffers.

> ffff8801549cc780 288953559 S Zo:6:007:1 -115:1:0 1 -18:0:176 176 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
> ffff8801549cca80 288953569 S Zo:6:007:1 -115:1:0 1 -18:0:176 176 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000

Here the pipeline is started by writing two buffers of zeros.

> ffff8801549cc780 288964489 C Zo:6:007:1 0:1:217621:0 1 0:0:176 176 >
> ffff8801549cc780 288964505 S Zo:6:007:1 -115:1:217621 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff8801549cca80 288965508 C Zo:6:007:1 0:1:217622:0 1 0:0:176 176 >
> ffff8801549cca80 288965527 S Zo:6:007:1 -115:1:217622 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff

In the remainder, each time a buffer completes, a new one is
submitted.  This implies a latency of less than 1 ms.  Evidently that
works okay on your system, but it won't work everywhere.

> ffff8801549cc780 288966486 C Zo:6:007:1 0:1:217623:0 1 0:0:176 176 >
> ffff8801549cc780 288966503 S Zo:6:007:1 -115:1:217623 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff8801549cca80 288967488 C Zo:6:007:1 0:1:217624:0 1 0:0:176 176 >
> ffff8801549cca80 288967507 S Zo:6:007:1 -115:1:217624 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff8801549cc780 288968508 C Zo:6:007:1 0:1:217625:0 1 0:0:176 176 >
> ffff8801549cc780 288968523 S Zo:6:007:1 -115:1:217625 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff8801549cca80 288969485 C Zo:6:007:1 0:1:217626:0 1 0:0:176 176 >
> ffff8801549cca80 288969499 S Zo:6:007:1 -115:1:217626 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff8801549cc780 288970507 C Zo:6:007:1 0:1:217627:0 1 0:0:176 176 >
> ffff8801549cc780 288970520 S Zo:6:007:1 -115:1:217627 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff8801549cca80 288971487 C Zo:6:007:1 0:1:217628:0 1 0:0:176 176 >
...

I won't include the whole log.  It's worth noticing that the URB
completion lines (the lines with "C") show no -EXDEV (-18) errors, and
the frame numbers increase sequentially (217623, 217624, 217625,
...).  This is consistent with the sound being produced correctly.

> root@richardiv:~# # Generated only opening and closing clicks
> 
> root@richardiv:~# uname -a; cat /sys/kernel/debug/usb/usbmon/4u & perl -e 'print pack "H*", "00FF" x 2048' | aplay --period-size=48 -r 44100 -f S16_LE -c2 -D hw:1,0; kill %1
> Linux richardiv 3.8-trunk-amd64 #1 SMP Debian 3.8-1~experimental.1 x86_64 GNU/Linux

> ffff880143c80d80 3864232940 C Zo:4:002:1 0:1:1057125:0 1 0:0:176 176 >
> ffff880143c80d80 3864232956 S Zo:4:002:1 -115:1:1057125 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff880143c80180 3864233934 C Zo:4:002:1 0:1:1057126:0 1 0:0:176 176 >
> ffff880143c80180 3864233955 S Zo:4:002:1 -115:1:1057126 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff880143c80d80 3864235913 C Zo:4:002:1 0:1:1057128:0 1 0:0:176 176 >
> ffff880143c80d80 3864235932 S Zo:4:002:1 -115:1:1057128 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff880143c80180 3864236910 C Zo:4:002:1 0:1:1057129:0 1 0:0:176 176 >
> ffff880143c80180 3864236927 S Zo:4:002:1 -115:1:1057129 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
> ffff880143c80d80 3864238939 C Zo:4:002:1 0:1:1057131:0 1 0:0:176 176 >
...

This trace shows that the frame numbers do not increase sequentially:
1057125, 1057126, 1057128, 1057129, 1053131, ...  This is because the
new driver is a little more conservative than the old driver,
requiring latencies to be larger than 1 ms.  You can see this 
explicitly in one of the new lines added by the commit you found:

+		next = uhci->frame_number + 2;

That 2 is the minimum latency, in frames (one frame per ms).

Anyway, the solution is simple: The audio driver needs either to submit
buffers that are at least 2 ms long, or to use more than two buffers
(or both).  What the appropriate command parameters for aplay should
be, I can't tell you.

> Should I capture enumeration and setup, too?

No need.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe alsa-devel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

_______________________________________________
Alsa-devel mailing list
Alsa-devel@alsa-project.org
http://mailman.alsa-project.org/mailman/listinfo/alsa-devel

Re: [alsa-devel] BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Clemens Ladisch]

Alan Stern wrote:
> ...
> This trace shows that the frame numbers do not increase sequentially:
> 1057125, 1057126, 1057128, 1057129, 1053131, ...  This is because the
> new driver is a little more conservative than the old driver,
> requiring latencies to be larger than 1 ms.  You can see this
> explicitly in one of the new lines added by the commit you found:
>
> +		next = uhci->frame_number + 2;
>
> That 2 is the minimum latency, in frames (one frame per ms).

One frame worked fine with the old driver.  What is the reason for
this regression?

> Anyway, the solution is simple: The audio driver needs either to submit
> buffers that are at least 2 ms long, or to use more than two buffers
> (or both).

The audio driver already has the infrastructure to cope for hardware
restrictions like this, it just needs to *know* about them.  How can
it detect that it runs on the OHCI/UHCI drivers?


Regards,
Clemens
--
To unsubscribe from this list: send the line "unsubscribe alsa-devel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

_______________________________________________
Alsa-devel mailing list
Alsa-devel@alsa-project.org
http://mailman.alsa-project.org/mailman/listinfo/alsa-devel

Re: [alsa-devel] BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Alan Stern]

On Fri, 19 Apr 2013, Clemens Ladisch wrote:

> Alan Stern wrote:
> > ...
> > This trace shows that the frame numbers do not increase sequentially:
> > 1057125, 1057126, 1057128, 1057129, 1053131, ...  This is because the
> > new driver is a little more conservative than the old driver,
> > requiring latencies to be larger than 1 ms.  You can see this
> > explicitly in one of the new lines added by the commit you found:
> >
> > +		next = uhci->frame_number + 2;
> >
> > That 2 is the minimum latency, in frames (one frame per ms).
> 
> One frame worked fine with the old driver.  What is the reason for
> this regression?

The semantics of URB_ISO_ASAP changed; now the driver interprets as
meaning "the earliest time that is certain to work".  Since I wasn't
sure that a 1-ms latency would always work, I increased the minimum to
2.

Perhaps that was a mistake.  Joe, you can try changing the 2 above to a 
1 to see if it fixes the problem.

> > Anyway, the solution is simple: The audio driver needs either to submit
> > buffers that are at least 2 ms long, or to use more than two buffers
> > (or both).
> 
> The audio driver already has the infrastructure to cope for hardware
> restrictions like this, it just needs to *know* about them.  How can
> it detect that it runs on the OHCI/UHCI drivers?

That is a very good question.  In fact, the audio driver shouldn't care 
about what kind of driver is used at the lower level; all it should 
care about are bounds on the latency.

The kernel's USB API doesn't provide this information, unfortunately.  
There should be a way for drivers to find out, for any USB device:

     A.	The maximum delay time needed for starting a new isochronous
	stream;

     B.	The minimum advance time required for submitting a new URB
	to an existing isochronous stream (i.e., the minimum pipeline
	size);

     C.	The maximum time into the future that isochronous URBs can be 
	scheduled (the maximum pipeline size).

I don't think there's any way to add this information into all of the 
existing host controller drivers, though.

For now, the best approach is to be conservative.  I believe all the
existing USB host controller drivers will work okay if you assume the
following values:

	A: 50 ms;

	B: 2 ms;

	C: 200 ms.

The audio driver probably doesn't care about A; you try to start a new 
stream and it gets going whenever the HCD chooses.  You may or may not 
care about C.  B is the important one for this discussion.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe alsa-devel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

_______________________________________________
Alsa-devel mailing list
Alsa-devel@alsa-project.org
http://mailman.alsa-project.org/mailman/listinfo/alsa-devel

Re: BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Joe Rayhawk]

[-- Attachment #1.1: Type: text/plain, Size: 7020 bytes --]

On Fri, Apr 19, 2013 at 02:18:24PM -0400, Alan Stern wrote:
> On Fri, 19 Apr 2013, Clemens Ladisch wrote:
> > Alan Stern wrote:
> > > +		next = uhci->frame_number + 2;
> > >
> > > That 2 is the minimum latency, in frames (one frame per ms).
> > 
> > One frame worked fine with the old driver.  What is the reason for
> > this regression?
> 
> Perhaps that was a mistake.  Joe, you can try changing the 2 above to a 
> 1 to see if it fixes the problem.

Hey, that worked great! Audio's coming through continuously, now.

root@richardiv:~# uname -a; cat /sys/kernel/debug/usb/usbmon/4u & perl -e 'print pack "H*", "00FF" x 2048' | aplay --period-size=48 -r 44100 -f S16_LE -c2 -D hw:1,0; kill %1
Linux richardiv 3.9.0-rc7-nextframe #8 SMP Fri Apr 19 16:29:37 PDT 2013 x86_64 GNU/Linux
[1] 4598
Playing raw data 'stdin' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
ffff880154aba440 3793290194 S Co:4:005:0 s 01 0b 0001 0001 0000 0
ffff880154aba440 3793292190 C Co:4:005:0 0 0
ffff8801515a20c0 3793292289 S Co:4:005:0 s 22 01 0100 0001 0003 3 = 44ac00
ffff8801515a20c0 3793293167 C Co:4:005:0 0 3 >
ffff8801515a20c0 3793293206 S Ci:4:005:0 s a2 81 0100 0001 0003 3 <
ffff8801515a20c0 3793294188 C Ci:4:005:0 0 3 = 44ac00
ffff880142054dc0 3793294216 S Zo:4:005:1 -115:1:0 1 -18:0:176 176 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
ffff8801420541c0 3793294221 S Zo:4:005:1 -115:1:0 1 -18:0:176 176 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
ffff880142054dc0 3793305177 C Zo:4:005:1 0:1:362330:0 1 0:0:176 176 >
ffff880142054dc0 3793305202 S Zo:4:005:1 -115:1:362330 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793306165 C Zo:4:005:1 0:1:362331:0 1 0:0:176 176 >
ffff8801420541c0 3793306186 S Zo:4:005:1 -115:1:362331 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793307191 C Zo:4:005:1 0:1:362332:0 1 0:0:176 176 >
ffff880142054dc0 3793307208 S Zo:4:005:1 -115:1:362332 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793308190 C Zo:4:005:1 0:1:362333:0 1 0:0:176 176 >
ffff8801420541c0 3793308203 S Zo:4:005:1 -115:1:362333 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793309191 C Zo:4:005:1 0:1:362334:0 1 0:0:176 176 >
ffff880142054dc0 3793309209 S Zo:4:005:1 -115:1:362334 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793310194 C Zo:4:005:1 0:1:362335:0 1 0:0:176 176 >
ffff8801420541c0 3793310211 S Zo:4:005:1 -115:1:362335 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793311192 C Zo:4:005:1 0:1:362336:0 1 0:0:176 176 >
ffff880142054dc0 3793311211 S Zo:4:005:1 -115:1:362336 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793312194 C Zo:4:005:1 0:1:362337:0 1 0:0:176 176 >
ffff8801420541c0 3793312212 S Zo:4:005:1 -115:1:362337 1 -18:0:180 180 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793313172 C Zo:4:005:1 0:1:362338:0 1 0:0:176 176 >
ffff880142054dc0 3793313188 S Zo:4:005:1 -115:1:362338 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793314192 C Zo:4:005:1 0:1:362339:0 1 0:0:180 180 >
ffff8801420541c0 3793314209 S Zo:4:005:1 -115:1:362339 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793315192 C Zo:4:005:1 0:1:362340:0 1 0:0:176 176 >
ffff880142054dc0 3793315210 S Zo:4:005:1 -115:1:362340 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793316192 C Zo:4:005:1 0:1:362341:0 1 0:0:176 176 >
ffff8801420541c0 3793316209 S Zo:4:005:1 -115:1:362341 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793317196 C Zo:4:005:1 0:1:362342:0 1 0:0:176 176 >
ffff880142054dc0 3793317207 S Zo:4:005:1 -115:1:362342 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793318191 C Zo:4:005:1 0:1:362343:0 1 0:0:176 176 >
ffff8801420541c0 3793318209 S Zo:4:005:1 -115:1:362343 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793319193 C Zo:4:005:1 0:1:362344:0 1 0:0:176 176 >
ffff880142054dc0 3793319211 S Zo:4:005:1 -115:1:362344 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793320191 C Zo:4:005:1 0:1:362345:0 1 0:0:176 176 >
ffff8801420541c0 3793320208 S Zo:4:005:1 -115:1:362345 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793321196 C Zo:4:005:1 0:1:362346:0 1 0:0:176 176 >
ffff880142054dc0 3793321213 S Zo:4:005:1 -115:1:362346 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793322191 C Zo:4:005:1 0:1:362347:0 1 0:0:176 176 >
ffff8801420541c0 3793322208 S Zo:4:005:1 -115:1:362347 1 -18:0:180 180 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793323193 C Zo:4:005:1 0:1:362348:0 1 0:0:176 176 >
ffff880142054dc0 3793323210 S Zo:4:005:1 -115:1:362348 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793324191 C Zo:4:005:1 0:1:362349:0 1 0:0:180 180 >
ffff8801420541c0 3793324208 S Zo:4:005:1 -115:1:362349 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793325196 C Zo:4:005:1 0:1:362350:0 1 0:0:176 176 >
ffff880142054dc0 3793325213 S Zo:4:005:1 -115:1:362350 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793326192 C Zo:4:005:1 0:1:362351:0 1 0:0:176 176 >
ffff8801420541c0 3793326209 S Zo:4:005:1 -115:1:362351 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793327196 C Zo:4:005:1 0:1:362352:0 1 0:0:176 176 >
ffff880142054dc0 3793327216 S Zo:4:005:1 -115:1:362352 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793328190 C Zo:4:005:1 0:1:362353:0 1 0:0:176 176 >
ffff8801420541c0 3793328220 S Zo:4:005:1 -115:1:362353 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793329165 C Zo:4:005:1 -104:1:362354:0 1 0:0:176 176 >
ffff8801420541c0 3793330191 C Zo:4:005:1 0:1:362355:0 1 0:0:176 176 >
ffff880154ae6c80 3793333265 S Co:4:005:0 s 01 0b 0000 0001 0000 0
ffff880154ae6c80 3793335191 C Co:4:005:0 0 0
root@richardiv:~# 


[-- Attachment #1.2: Digital signature --]
[-- Type: application/pgp-signature, Size: 836 bytes --]

[-- Attachment #2: Type: text/plain, Size: 0 bytes --]

Re: [alsa-devel] BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Joe Rayhawk]

[-- Attachment #1.1: Type: text/plain, Size: 7020 bytes --]

On Fri, Apr 19, 2013 at 02:18:24PM -0400, Alan Stern wrote:
> On Fri, 19 Apr 2013, Clemens Ladisch wrote:
> > Alan Stern wrote:
> > > +		next = uhci->frame_number + 2;
> > >
> > > That 2 is the minimum latency, in frames (one frame per ms).
> > 
> > One frame worked fine with the old driver.  What is the reason for
> > this regression?
> 
> Perhaps that was a mistake.  Joe, you can try changing the 2 above to a 
> 1 to see if it fixes the problem.

Hey, that worked great! Audio's coming through continuously, now.

root@richardiv:~# uname -a; cat /sys/kernel/debug/usb/usbmon/4u & perl -e 'print pack "H*", "00FF" x 2048' | aplay --period-size=48 -r 44100 -f S16_LE -c2 -D hw:1,0; kill %1
Linux richardiv 3.9.0-rc7-nextframe #8 SMP Fri Apr 19 16:29:37 PDT 2013 x86_64 GNU/Linux
[1] 4598
Playing raw data 'stdin' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo
ffff880154aba440 3793290194 S Co:4:005:0 s 01 0b 0001 0001 0000 0
ffff880154aba440 3793292190 C Co:4:005:0 0 0
ffff8801515a20c0 3793292289 S Co:4:005:0 s 22 01 0100 0001 0003 3 = 44ac00
ffff8801515a20c0 3793293167 C Co:4:005:0 0 3 >
ffff8801515a20c0 3793293206 S Ci:4:005:0 s a2 81 0100 0001 0003 3 <
ffff8801515a20c0 3793294188 C Ci:4:005:0 0 3 = 44ac00
ffff880142054dc0 3793294216 S Zo:4:005:1 -115:1:0 1 -18:0:176 176 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
ffff8801420541c0 3793294221 S Zo:4:005:1 -115:1:0 1 -18:0:176 176 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
ffff880142054dc0 3793305177 C Zo:4:005:1 0:1:362330:0 1 0:0:176 176 >
ffff880142054dc0 3793305202 S Zo:4:005:1 -115:1:362330 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793306165 C Zo:4:005:1 0:1:362331:0 1 0:0:176 176 >
ffff8801420541c0 3793306186 S Zo:4:005:1 -115:1:362331 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793307191 C Zo:4:005:1 0:1:362332:0 1 0:0:176 176 >
ffff880142054dc0 3793307208 S Zo:4:005:1 -115:1:362332 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793308190 C Zo:4:005:1 0:1:362333:0 1 0:0:176 176 >
ffff8801420541c0 3793308203 S Zo:4:005:1 -115:1:362333 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793309191 C Zo:4:005:1 0:1:362334:0 1 0:0:176 176 >
ffff880142054dc0 3793309209 S Zo:4:005:1 -115:1:362334 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793310194 C Zo:4:005:1 0:1:362335:0 1 0:0:176 176 >
ffff8801420541c0 3793310211 S Zo:4:005:1 -115:1:362335 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793311192 C Zo:4:005:1 0:1:362336:0 1 0:0:176 176 >
ffff880142054dc0 3793311211 S Zo:4:005:1 -115:1:362336 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793312194 C Zo:4:005:1 0:1:362337:0 1 0:0:176 176 >
ffff8801420541c0 3793312212 S Zo:4:005:1 -115:1:362337 1 -18:0:180 180 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793313172 C Zo:4:005:1 0:1:362338:0 1 0:0:176 176 >
ffff880142054dc0 3793313188 S Zo:4:005:1 -115:1:362338 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793314192 C Zo:4:005:1 0:1:362339:0 1 0:0:180 180 >
ffff8801420541c0 3793314209 S Zo:4:005:1 -115:1:362339 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793315192 C Zo:4:005:1 0:1:362340:0 1 0:0:176 176 >
ffff880142054dc0 3793315210 S Zo:4:005:1 -115:1:362340 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793316192 C Zo:4:005:1 0:1:362341:0 1 0:0:176 176 >
ffff8801420541c0 3793316209 S Zo:4:005:1 -115:1:362341 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793317196 C Zo:4:005:1 0:1:362342:0 1 0:0:176 176 >
ffff880142054dc0 3793317207 S Zo:4:005:1 -115:1:362342 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793318191 C Zo:4:005:1 0:1:362343:0 1 0:0:176 176 >
ffff8801420541c0 3793318209 S Zo:4:005:1 -115:1:362343 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793319193 C Zo:4:005:1 0:1:362344:0 1 0:0:176 176 >
ffff880142054dc0 3793319211 S Zo:4:005:1 -115:1:362344 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793320191 C Zo:4:005:1 0:1:362345:0 1 0:0:176 176 >
ffff8801420541c0 3793320208 S Zo:4:005:1 -115:1:362345 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793321196 C Zo:4:005:1 0:1:362346:0 1 0:0:176 176 >
ffff880142054dc0 3793321213 S Zo:4:005:1 -115:1:362346 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793322191 C Zo:4:005:1 0:1:362347:0 1 0:0:176 176 >
ffff8801420541c0 3793322208 S Zo:4:005:1 -115:1:362347 1 -18:0:180 180 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793323193 C Zo:4:005:1 0:1:362348:0 1 0:0:176 176 >
ffff880142054dc0 3793323210 S Zo:4:005:1 -115:1:362348 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793324191 C Zo:4:005:1 0:1:362349:0 1 0:0:180 180 >
ffff8801420541c0 3793324208 S Zo:4:005:1 -115:1:362349 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793325196 C Zo:4:005:1 0:1:362350:0 1 0:0:176 176 >
ffff880142054dc0 3793325213 S Zo:4:005:1 -115:1:362350 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793326192 C Zo:4:005:1 0:1:362351:0 1 0:0:176 176 >
ffff8801420541c0 3793326209 S Zo:4:005:1 -115:1:362351 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793327196 C Zo:4:005:1 0:1:362352:0 1 0:0:176 176 >
ffff880142054dc0 3793327216 S Zo:4:005:1 -115:1:362352 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff8801420541c0 3793328190 C Zo:4:005:1 0:1:362353:0 1 0:0:176 176 >
ffff8801420541c0 3793328220 S Zo:4:005:1 -115:1:362353 1 -18:0:176 176 = 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff 00ff00ff
ffff880142054dc0 3793329165 C Zo:4:005:1 -104:1:362354:0 1 0:0:176 176 >
ffff8801420541c0 3793330191 C Zo:4:005:1 0:1:362355:0 1 0:0:176 176 >
ffff880154ae6c80 3793333265 S Co:4:005:0 s 01 0b 0000 0001 0000 0
ffff880154ae6c80 3793335191 C Co:4:005:0 0 0
root@richardiv:~# 


[-- Attachment #1.2: Digital signature --]
[-- Type: application/pgp-signature, Size: 836 bytes --]

[-- Attachment #2: Type: text/plain, Size: 160 bytes --]

_______________________________________________
Alsa-devel mailing list
Alsa-devel@alsa-project.org
http://mailman.alsa-project.org/mailman/listinfo/alsa-devel

Re: [alsa-devel] BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Alan Stern]

On Fri, 19 Apr 2013, Joe Rayhawk wrote:

> On Fri, Apr 19, 2013 at 02:18:24PM -0400, Alan Stern wrote:
> > On Fri, 19 Apr 2013, Clemens Ladisch wrote:
> > > Alan Stern wrote:
> > > > +		next = uhci->frame_number + 2;
> > > >
> > > > That 2 is the minimum latency, in frames (one frame per ms).
> > > 
> > > One frame worked fine with the old driver.  What is the reason for
> > > this regression?
> > 
> > Perhaps that was a mistake.  Joe, you can try changing the 2 above to a 
> > 1 to see if it fixes the problem.
> 
> Hey, that worked great! Audio's coming through continuously, now.

This change could be added to the driver, but I would prefer not to.  
In any case, it would be best if the usb-audio driver were changed to
keep the pipeline length at least 2 ms at all times.

Clemens, what do you suggest?

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe alsa-devel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

_______________________________________________
Alsa-devel mailing list
Alsa-devel@alsa-project.org
http://mailman.alsa-project.org/mailman/listinfo/alsa-devel

Re: [alsa-devel] BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Clemens Ladisch]

Alan Stern wrote:
> On Fri, 19 Apr 2013, Joe Rayhawk wrote:
>> On Fri, Apr 19, 2013 at 02:18:24PM -0400, Alan Stern wrote:
>>> On Fri, 19 Apr 2013, Clemens Ladisch wrote:
>>>> Alan Stern wrote:
>>>>> +		next = uhci->frame_number + 2;
>>>>>
>>>>> That 2 is the minimum latency, in frames (one frame per ms).
>>>>
>>>> One frame worked fine with the old driver.  What is the reason for
>>>> this regression?
>>>
>>> Perhaps that was a mistake.  Joe, you can try changing the 2 above to a
>>> 1 to see if it fixes the problem.
>>
>> Hey, that worked great! Audio's coming through continuously, now.
>
> This change could be added to the driver, but I would prefer not to.

Why do you think it is necessary to have a minimum latency of 2 ms?

Again, the old algorithm worked fine.  While such short queues are not
used by default, they are necessary to get low latencies for real-time
audio applications.  Keeping this change would keep this regression for
quite a few people.

> In any case, it would be best

What criteria are you using to evaluate the benefit of this?  Do you
want to reduce the chance of queue underruns?  Interrupts?  Power usage?

> if the usb-audio driver were changed to keep the pipeline length at
> least 2 ms at all times.

Why is having a queue of two URB with one packet each suddenly not
allowed?


Regards,
Clemens
--
To unsubscribe from this list: send the line "unsubscribe alsa-devel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

_______________________________________________
Alsa-devel mailing list
Alsa-devel@alsa-project.org
http://mailman.alsa-project.org/mailman/listinfo/alsa-devel

Re: BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Alan Stern]

On Tue, 23 Apr 2013, Clemens Ladisch wrote:

> Alan Stern wrote:
> > On Fri, 19 Apr 2013, Joe Rayhawk wrote:
> >> On Fri, Apr 19, 2013 at 02:18:24PM -0400, Alan Stern wrote:
> >>> On Fri, 19 Apr 2013, Clemens Ladisch wrote:
> >>>> Alan Stern wrote:
> >>>>> +		next = uhci->frame_number + 2;
> >>>>>
> >>>>> That 2 is the minimum latency, in frames (one frame per ms).
> >>>>
> >>>> One frame worked fine with the old driver.  What is the reason for
> >>>> this regression?
> >>>
> >>> Perhaps that was a mistake.  Joe, you can try changing the 2 above to a
> >>> 1 to see if it fixes the problem.
> >>
> >> Hey, that worked great! Audio's coming through continuously, now.
> >
> > This change could be added to the driver, but I would prefer not to.
> 
> Why do you think it is necessary to have a minimum latency of 2 ms?

To avoid underruns.  Perhaps this is unnecessary caution on my part.

> Again, the old algorithm worked fine.  While such short queues are not
> used by default, they are necessary to get low latencies for real-time
> audio applications.  Keeping this change would keep this regression for
> quite a few people.

Okay, I will change the 2 to 1 since you think that is best.

> > In any case, it would be best
> 
> What criteria are you using to evaluate the benefit of this?  Do you
> want to reduce the chance of queue underruns?  Interrupts?  Power usage?

Chance of underruns.

> > if the usb-audio driver were changed to keep the pipeline length at
> > least 2 ms at all times.
> 
> Why is having a queue of two URB with one packet each suddenly not
> allowed?

It _is_ allowed when URB_ISO_ASAP is clear.  I have never fully 
understood why the audio driver sets that flag.  By setting it, you are 
telling the host controller driver that you are willing to give up 
reduced latency in order to avoid underruns.

Alan Stern

Re: [alsa-devel] BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Alan Stern]

On Tue, 23 Apr 2013, Clemens Ladisch wrote:

> Alan Stern wrote:
> > On Fri, 19 Apr 2013, Joe Rayhawk wrote:
> >> On Fri, Apr 19, 2013 at 02:18:24PM -0400, Alan Stern wrote:
> >>> On Fri, 19 Apr 2013, Clemens Ladisch wrote:
> >>>> Alan Stern wrote:
> >>>>> +		next = uhci->frame_number + 2;
> >>>>>
> >>>>> That 2 is the minimum latency, in frames (one frame per ms).
> >>>>
> >>>> One frame worked fine with the old driver.  What is the reason for
> >>>> this regression?
> >>>
> >>> Perhaps that was a mistake.  Joe, you can try changing the 2 above to a
> >>> 1 to see if it fixes the problem.
> >>
> >> Hey, that worked great! Audio's coming through continuously, now.
> >
> > This change could be added to the driver, but I would prefer not to.
> 
> Why do you think it is necessary to have a minimum latency of 2 ms?

To avoid underruns.  Perhaps this is unnecessary caution on my part.

> Again, the old algorithm worked fine.  While such short queues are not
> used by default, they are necessary to get low latencies for real-time
> audio applications.  Keeping this change would keep this regression for
> quite a few people.

Okay, I will change the 2 to 1 since you think that is best.

> > In any case, it would be best
> 
> What criteria are you using to evaluate the benefit of this?  Do you
> want to reduce the chance of queue underruns?  Interrupts?  Power usage?

Chance of underruns.

> > if the usb-audio driver were changed to keep the pipeline length at
> > least 2 ms at all times.
> 
> Why is having a queue of two URB with one packet each suddenly not
> allowed?

It _is_ allowed when URB_ISO_ASAP is clear.  I have never fully 
understood why the audio driver sets that flag.  By setting it, you are 
telling the host controller driver that you are willing to give up 
reduced latency in order to avoid underruns.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe alsa-devel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

_______________________________________________
Alsa-devel mailing list
Alsa-devel@alsa-project.org
http://mailman.alsa-project.org/mailman/listinfo/alsa-devel

Re: BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Clemens Ladisch]

Alan Stern wrote:
> On Tue, 23 Apr 2013, Clemens Ladisch wrote:
>> Why is having a queue of two URB with one packet each suddenly not
>> allowed?
>
> It _is_ allowed when URB_ISO_ASAP is clear.  I have never fully
> understood why the audio driver sets that flag.  By setting it, you are
> telling the host controller driver that you are willing to give up
> reduced latency in order to avoid underruns.

This flag was needed to avoid having to set urb->start_frame.

With the changed queueing API, the audio driver needs to change too.
I'll look into this ...


Regards,
Clemens

Re: [alsa-devel] BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Clemens Ladisch]

Alan Stern wrote:
> On Tue, 23 Apr 2013, Clemens Ladisch wrote:
>> Why is having a queue of two URB with one packet each suddenly not
>> allowed?
>
> It _is_ allowed when URB_ISO_ASAP is clear.  I have never fully
> understood why the audio driver sets that flag.  By setting it, you are
> telling the host controller driver that you are willing to give up
> reduced latency in order to avoid underruns.

This flag was needed to avoid having to set urb->start_frame.

With the changed queueing API, the audio driver needs to change too.
I'll look into this ...


Regards,
Clemens
--
To unsubscribe from this list: send the line "unsubscribe alsa-devel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

_______________________________________________
Alsa-devel mailing list
Alsa-devel@alsa-project.org
http://mailman.alsa-project.org/mailman/listinfo/alsa-devel

Re: [alsa-devel] BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Alan Stern]

On Tue, 23 Apr 2013, Clemens Ladisch wrote:

> Alan Stern wrote:
> > On Tue, 23 Apr 2013, Clemens Ladisch wrote:
> >> Why is having a queue of two URB with one packet each suddenly not
> >> allowed?
> >
> > It _is_ allowed when URB_ISO_ASAP is clear.  I have never fully
> > understood why the audio driver sets that flag.  By setting it, you are
> > telling the host controller driver that you are willing to give up
> > reduced latency in order to avoid underruns.
> 
> This flag was needed to avoid having to set urb->start_frame.

Ah, okay.  It is now unnecessary to set urb->start_frame; in fact that 
field is now output-only.

(To be fair, I haven't checked _all_ the HCDs in this regard, just 
uhci-hcd, ohci-hcd, and ehci-hcd.  However, if any other HCD requires 
urb->start_frame to be set then that HCD should be considered buggy and 
should be fixed.)

> With the changed queueing API, the audio driver needs to change too.
> I'll look into this ...

Let me know if you have any questions.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe alsa-devel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

_______________________________________________
Alsa-devel mailing list
Alsa-devel@alsa-project.org
http://mailman.alsa-project.org/mailman/listinfo/alsa-devel

Re: BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Alan Stern]

On Tue, 23 Apr 2013, Clemens Ladisch wrote:

> Alan Stern wrote:
> > On Tue, 23 Apr 2013, Clemens Ladisch wrote:
> >> Why is having a queue of two URB with one packet each suddenly not
> >> allowed?
> >
> > It _is_ allowed when URB_ISO_ASAP is clear.  I have never fully
> > understood why the audio driver sets that flag.  By setting it, you are
> > telling the host controller driver that you are willing to give up
> > reduced latency in order to avoid underruns.
> 
> This flag was needed to avoid having to set urb->start_frame.

Ah, okay.  It is now unnecessary to set urb->start_frame; in fact that 
field is now output-only.

(To be fair, I haven't checked _all_ the HCDs in this regard, just 
uhci-hcd, ohci-hcd, and ehci-hcd.  However, if any other HCD requires 
urb->start_frame to be set then that HCD should be considered buggy and 
should be fixed.)

> With the changed queueing API, the audio driver needs to change too.
> I'll look into this ...

Let me know if you have any questions.

Alan Stern

Re: BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Clemens Ladisch]

Alan Stern wrote:
> On Fri, 19 Apr 2013, Joe Rayhawk wrote:
>> On Fri, Apr 19, 2013 at 02:18:24PM -0400, Alan Stern wrote:
>>> On Fri, 19 Apr 2013, Clemens Ladisch wrote:
>>>> Alan Stern wrote:
>>>>> +		next = uhci->frame_number + 2;
>>>>>
>>>>> That 2 is the minimum latency, in frames (one frame per ms).
>>>>
>>>> One frame worked fine with the old driver.  What is the reason for
>>>> this regression?
>>>
>>> Perhaps that was a mistake.  Joe, you can try changing the 2 above to a
>>> 1 to see if it fixes the problem.
>>
>> Hey, that worked great! Audio's coming through continuously, now.
>
> This change could be added to the driver, but I would prefer not to.

Why do you think it is necessary to have a minimum latency of 2 ms?

Again, the old algorithm worked fine.  While such short queues are not
used by default, they are necessary to get low latencies for real-time
audio applications.  Keeping this change would keep this regression for
quite a few people.

> In any case, it would be best

What criteria are you using to evaluate the benefit of this?  Do you
want to reduce the chance of queue underruns?  Interrupts?  Power usage?

> if the usb-audio driver were changed to keep the pipeline length at
> least 2 ms at all times.

Why is having a queue of two URB with one packet each suddenly not
allowed?


Regards,
Clemens

Re: BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Alan Stern]

On Fri, 19 Apr 2013, Joe Rayhawk wrote:

> On Fri, Apr 19, 2013 at 02:18:24PM -0400, Alan Stern wrote:
> > On Fri, 19 Apr 2013, Clemens Ladisch wrote:
> > > Alan Stern wrote:
> > > > +		next = uhci->frame_number + 2;
> > > >
> > > > That 2 is the minimum latency, in frames (one frame per ms).
> > > 
> > > One frame worked fine with the old driver.  What is the reason for
> > > this regression?
> > 
> > Perhaps that was a mistake.  Joe, you can try changing the 2 above to a 
> > 1 to see if it fixes the problem.
> 
> Hey, that worked great! Audio's coming through continuously, now.

This change could be added to the driver, but I would prefer not to.  
In any case, it would be best if the usb-audio driver were changed to
keep the pipeline length at least 2 ms at all times.

Clemens, what do you suggest?

Alan Stern

Re: BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Alan Stern]

On Fri, 19 Apr 2013, Clemens Ladisch wrote:

> Alan Stern wrote:
> > ...
> > This trace shows that the frame numbers do not increase sequentially:
> > 1057125, 1057126, 1057128, 1057129, 1053131, ...  This is because the
> > new driver is a little more conservative than the old driver,
> > requiring latencies to be larger than 1 ms.  You can see this
> > explicitly in one of the new lines added by the commit you found:
> >
> > +		next = uhci->frame_number + 2;
> >
> > That 2 is the minimum latency, in frames (one frame per ms).
> 
> One frame worked fine with the old driver.  What is the reason for
> this regression?

The semantics of URB_ISO_ASAP changed; now the driver interprets as
meaning "the earliest time that is certain to work".  Since I wasn't
sure that a 1-ms latency would always work, I increased the minimum to
2.

Perhaps that was a mistake.  Joe, you can try changing the 2 above to a 
1 to see if it fixes the problem.

> > Anyway, the solution is simple: The audio driver needs either to submit
> > buffers that are at least 2 ms long, or to use more than two buffers
> > (or both).
> 
> The audio driver already has the infrastructure to cope for hardware
> restrictions like this, it just needs to *know* about them.  How can
> it detect that it runs on the OHCI/UHCI drivers?

That is a very good question.  In fact, the audio driver shouldn't care 
about what kind of driver is used at the lower level; all it should 
care about are bounds on the latency.

The kernel's USB API doesn't provide this information, unfortunately.  
There should be a way for drivers to find out, for any USB device:

     A.	The maximum delay time needed for starting a new isochronous
	stream;

     B.	The minimum advance time required for submitting a new URB
	to an existing isochronous stream (i.e., the minimum pipeline
	size);

     C.	The maximum time into the future that isochronous URBs can be 
	scheduled (the maximum pipeline size).

I don't think there's any way to add this information into all of the 
existing host controller drivers, though.

For now, the best approach is to be conservative.  I believe all the
existing USB host controller drivers will work okay if you assume the
following values:

	A: 50 ms;

	B: 2 ms;

	C: 200 ms.

The audio driver probably doesn't care about A; you try to start a new 
stream and it gets going whenever the HCD chooses.  You may or may not 
care about C.  B is the important one for this discussion.

Alan Stern

Re: BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Clemens Ladisch]

Alan Stern wrote:
> ...
> This trace shows that the frame numbers do not increase sequentially:
> 1057125, 1057126, 1057128, 1057129, 1053131, ...  This is because the
> new driver is a little more conservative than the old driver,
> requiring latencies to be larger than 1 ms.  You can see this
> explicitly in one of the new lines added by the commit you found:
>
> +		next = uhci->frame_number + 2;
>
> That 2 is the minimum latency, in frames (one frame per ms).

One frame worked fine with the old driver.  What is the reason for
this regression?

> Anyway, the solution is simple: The audio driver needs either to submit
> buffers that are at least 2 ms long, or to use more than two buffers
> (or both).

The audio driver already has the infrastructure to cope for hardware
restrictions like this, it just needs to *know* about them.  How can
it detect that it runs on the OHCI/UHCI drivers?


Regards,
Clemens

Re: [alsa-devel] BUG: USB audio discontinuities with 'UHCI: implement new semantics for URB_ISO_ASAP'

[Alan Stern]

On Wed, 8 May 2013, Joe Rayhawk wrote:

> For what it's worth, the following -stable patch
> 
> "ALSA: USB: adjust for changed 3.8 USB API"
> c75c5ab575af7db707689cdbb5a5c458e9a034bb
> 
> fixes the discontinuous playback on period sizes between 139 and 192,
> but the discontinuous playback on period sizes between 48 and 138 has
> been replaced by rather worse kernel blocking and kernel errors:
> 
> jrayhawk@richardiv:~$ sudo tail -F -n 0 /var/log/kern.log &
> [1] 4490
> jrayhawk@richardiv:~$ time perl -e 'print pack "H*", "00FF" x 2048' | aplay --period-size=192 -r 48000 -f S16_LE -c2 -D hw:0,0
> Playing raw data 'stdin' : Signed 16 bit Little Endian, Rate 48000 Hz, Stereo
> 
> real	0m0.053s
> user	0m0.008s
> sys	0m0.000s
> jrayhawk@richardiv:~$ time perl -e 'print pack "H*", "00FF" x 2048' | aplay --period-size=48 -r 48000 -f S16_LE -c2 -D hw:0,0
> Playing raw data 'stdin' : Signed 16 bit Little Endian, Rate 48000 Hz, Stereo
> May  8 17:01:56 richardiv kernel: [ 1680.923474] cannot submit urb (err = -18)
> May  8 17:01:56 richardiv kernel: [ 1680.924472] cannot submit urb (err = -18)
> 
> real	0m10.023s
> user	0m0.008s
> sys	0m0.004s

I don't know if you want to investigate this in any detail.  If you do, 
please post a usbmon trace of a failed playback.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe alsa-devel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

_______________________________________________
Alsa-devel mailing list
Alsa-devel@alsa-project.org
http://mailman.alsa-project.org/mailman/listinfo/alsa-devel