Bugzilla – Bug 16233
mp3 stream with Xing header is handled wrong when proxied
Last modified: 2011-05-09 15:48:51 UTC
Reproduced on: SBS 7.5 & 7.5.1 nightly Touch Firmware 7.5 & 7.5.1 nightly Hardware: SB3 & Touch - Synced Touch - unsynced, solo Squeezeplay - solo, 7.5.1 nightly URL Causing problems: http://www.opb.org/programs/streams/opb-radio.pls Directly: http://stream1.opb.org/radio.mp3 The stream is a 48kpbs MP3, 24khz, apparently using Icecast to transcode. I'll log anything you want, but I haven't found anything specific in my logs causing the problem. To Reproduce: Tune into the URL above on a SB3, works great Tune into the URL on a Touch, and rebuffers continuously after 20 seconds Tune into the URL with Squeezeplay, plays like Chipmunks, and rebuffers continuously after 20 seconds
Another stream by the same provider streams perfectly: http://opbmusic.org/media/opbmusic.pls It is 64kpbs MP3 44.1khz
There is a 32kpbs, low-bitrate stream available, but I can't get it reliably with 7.5. With the Squeezeplay 7.5.1 nightly, it appears to stream, but the info screen still shows 48kbps. http://stream1.opb.org/radio_lbr.mp3
This stream plays OK on Touch for me.
(In reply to comment #3) > This stream plays OK on Touch for me. Andy, I did some more testing, and it looks like it's actually a sync & touch problem. (need both to reproduce) The solo Touch can play the stream fine, the SB3 can play the stream fine, but synced together, they (or just the touch, can't tell) timeout and rebuffer. If I sync 2 SB3's together, they play fine. Really killing my WAF. I'll take a workaround - any workaround - at this point.
First comment: the chipmunks issue is only with desktop Squeezeplay. I have not confirmed this. Second: the rebuffering when Touch is synced actually seems to be triggered by proxy streaming. Configuring SbS to use proxy streaming for a Touch even when not synced can reproduce this problem. From the Touch log: May 20 08:30:29 squeezeplay: DEBUG audio.decode - Playback.lua:356 resume decoder, 4344 bytes buffered, decode threshold 2048 May 20 08:30:29 squeezeplay: DEBUG audio.decode - decode_resume_decoder:573 decode_resume_decoder May 20 08:30:29 squeezeplay: DEBUG audio.decode - decode_resume_decoder_handler:117 resume_decoder decode state: 1 audio state 0 May 20 08:30:29 squeezeplay: DEBUG audio.decode - debug_fullness:107 fullness: 4344 / 0 | 0.14% / 0.00% May 20 08:30:29 squeezeplay: DEBUG audio.codec - xing_parse:82 xing magic 496e666f May 20 08:30:29 squeezeplay: DEBUG audio.codec - xing_parse:92 reading xing frames May 20 08:30:29 squeezeplay: DEBUG audio.codec - xing_parse:100 reading xing bytes May 20 08:30:29 squeezeplay: DEBUG audio.codec - xing_parse:108 reading xing toc May 20 08:30:29 squeezeplay: DEBUG audio.codec - xing_parse:116 reading xing scale May 20 08:30:29 squeezeplay: DEBUG audio.codec - xing_parse:133 lame magic 4c414d45 bitlen 336 May 20 08:30:29 squeezeplay: DEBUG audio.codec - xing_parse:157 encoder delay=1105 padding=1113 May 20 08:30:29 squeezeplay: DEBUG audio.codec - xing_parse:158 total frames 1105 May 20 08:30:29 squeezeplay: DEBUG audio.codec - decode_mad_output:379 Skip encoder_delay=1105 pcm->length=576 offset=576 May 20 08:30:29 squeezeplay: DEBUG audio.codec - decode_mad_output:379 Skip encoder_delay=529 pcm->length=576 offset=529 May 20 08:30:29 squeezeplay: DEBUG audio.decode - decode_output_samples:385 first buffer sample_rate=24000 May 20 08:30:29 squeezeplay: INFO audio.decode - Playback.lua:407 0.0%/1.7% May 20 08:30:30 squeezeplay: DEBUG audio.decode - Playback.lua:383 resume audio bytesReceivedL=18807 outputTime=1561 threshold=18432 May 20 08:30:30 squeezeplay: DEBUG audio.decode - decode_resume_audio:594 decode_resume_audio start_jiffies=0 May 20 08:30:30 squeezeplay: DEBUG audio.decode - decode_resume_audio_handler:133 decode_resume_audio_handler start_interval=0 May 20 08:30:30 squeezeplay: DEBUG audio.decode - debug_fullness:107 fullness: 4327 / 299896 | 0.14% / 8.50% May 20 08:30:30 squeezeplay: DEBUG audio.decode - decode_resume_audio_handler:149 resume_audio decode state: 1 audio state 40 May 20 08:30:30 squeezeplay: DEBUG audio.decode - Playback.lua:331 status TRACK STARTED (elapsed: 187) May 20 08:30:31 squeezeplay: INFO audio.decode - Playback.lua:407 0.0%/60.6% May 20 08:30:32 squeezeplay: INFO audio.decode - Playback.lua:407 0.0%/61.7% May 20 08:30:33 squeezeplay: INFO audio.decode - Playback.lua:407 0.0%/62.1% May 20 08:30:34 squeezeplay: INFO audio.decode - Playback.lua:407 0.0%/62.5% May 20 08:30:35 squeezeplay: INFO audio.decode - Playback.lua:407 0.0%/62.1% May 20 08:30:36 squeezeplay: INFO audio.decode - Playback.lua:407 0.0%/63.0% May 20 08:30:38 squeezeplay: INFO audio.decode - Playback.lua:407 0.0%/62.2% May 20 08:30:39 squeezeplay: INFO audio.decode - Playback.lua:407 0.0%/63.0% May 20 08:30:40 squeezeplay: INFO audio.decode - Playback.lua:407 0.0%/63.6% May 20 08:30:41 squeezeplay: INFO audio.decode - Playback.lua:407 0.0%/63.2% May 20 08:30:42 squeezeplay: INFO audio.decode - Playback.lua:407 0.0%/62.8% May 20 08:30:42 squeezeplay: DEBUG audio.codec - decode_mad_output:393 Remove encoder padding=1113 frames=39 May 20 08:30:42 squeezeplay: DEBUG audio.codec - decode_mad_output:393 Remove encoder padding=1113 frames=0 May 20 08:30:42 squeezeplay: DEBUG audio.codec - decode_mad_output:393 Remove encoder padding=1113 frames=0 May 20 08:30:42 squeezeplay: DEBUG audio.codec - decode_mad_output:393 Remove encoder padding=1113 frames=0 ... This comes from this code fragment: /* Remove encoder padding. Only do this if we are streaming a file, * some radio stations seem to incorrectly include a xing header in * the stream. */ if (self->encoder_padding && !streambuf_is_icy()) { if (pcm->length > self->frame_cnt ) { LOG_DEBUG(log_audio_codec, "Remove encoder padding=%d frames=%ld", self->encoder_padding, self->frame_cnt); pcm->length = self->frame_cnt; } } Note that this is only executed if !streambuf_is_icy(), which will be the case with proxy streaming.
Also reproduced using a Seattle NPR station, using their High Bitrate stream, not standard (64k). http://forums.slimdevices.com/showpost.php?p=549071&postcount=17 SB3 on its own works. Touch on its own works. Radio on its own works. SB3 + SB3 works. SB3 + Touch fails. SB3 + Radio fails. Touch + Radio fails. Looks like syncing with any Squeezeplay based device in the mix doesn't work. This is with 7.5.1. The problematic stream is at http://128.208.34.80:8002/
Created attachment 6860 [details] Proposed patch The problem streams all use the Icecast feature where you can prepend a promo file to all new stream connections. If this file has a Xing+LAME header in it, and the stream is proxied through SBS, we treated the stream as a local gapless file and ended up stripping all samples past the point where the LAME tag said the stream ended, so you would hear the promo and a few seconds of the stream. The fix was actually fairly complicated, as it was tricky to get a solution that worked for both normal LAME files and these streams. This patch adds a couple of new variables: lame_samples: Total expected samples based on the Xing header lame_samples_remain (used to be frame_cnt): Remaining accurate samples based on Xing - encoder delay - encoder padding decoded_samples: Total samples we have actually decoded At the end of lame_samples_remain, we start removing padding samples. This continues unless we see that we have decoded more samples than the lame_samples value (+1152 extra samples). If this happens we assume the header was invalid and begin outputting audio again. Normal files will never reach this point and are decoded as before, and these problem streams will hit this point and work fine.
I will ping Andy to commit his patch after the 7.5.1 release.
(In reply to comment #8) > I will ping Andy to commit his patch after the 7.5.1 release. Any chance getting this into a 7.5.1 nightly? That, or post a compiled binary to test? I assume this needs to go on the Touch, and I don't have an ARM cross-compiler configured. Thanks! -Dan
== Auto-comment from SVN commit #8827 to the jive repo by agrundman == == http://svn.slimdevices.com/jive?view=revision&revision=8827 == Fixed bug 16233, handle mp3 streams with invalid Xing frame count
This bug has re-appeared on the latest (few?) 7.6 nightlies Server: Version: 7.6.0 - r30936 @ Wed Jun 23 02:10:00 PDT 2010 Server HTTP Port Number: 9000 Operating system: Windows 7 - EN - cp1252 Platform Architecture: 586 Perl Version: 5.10.0 - MSWin32-x86-multi-thread Database Version: DBD::SQLite 1.29 (sqlite 3.6.22) Total Players Recognized: 4 Touch: Player Model: Squeezebox Touch Firmware: 7.5.1-r8837 Wireless Signal Strength: 100% Problem: Rebuffers after 22-23 seconds of playing an NPR MP3 Stream at: http://www.opb.org/programs/streams/opb-radio.pls Question: Is the Touch firmware supposed to be at 7.5.1-Rxxxx with a 7.6 server?
Apologies - the Touch wasn't getting a firmware update (Settings -> Advanced -> Software Update wasn't prompting for 7.6 firmware, perhaps a different problem). Wiping and reloading the server, re-installing the 7.6-r30936 nightly, and a reboot, prompted the Touch to download the correct firmware. This issue isn't fixed, though, in that there is a 100ms off-sync in the SB2/SB3 player now - setting a 100ms player audio delay re-syncs the stream. I haven't regressed this to see if it affects other streams, MP3's, etc. Player 1: Touch, sync settings: Maintain Sync, 0, 0, 10, 2 Player 2: SB2 (FW130), sync settings: Maintain Sync, 0, 100, 10, 2 -Dan (In reply to comment #11) > This bug has re-appeared on the latest (few?) 7.6 nightlies > > Server: > Version: 7.6.0 - r30936 @ Wed Jun 23 02:10:00 PDT 2010 > Server HTTP Port Number: 9000 > Operating system: Windows 7 - EN - cp1252 > Platform Architecture: 586 > Perl Version: 5.10.0 - MSWin32-x86-multi-thread > Database Version: DBD::SQLite 1.29 (sqlite 3.6.22) > Total Players Recognized: 4 > > Touch: > Player Model: Squeezebox Touch > Firmware: 7.5.1-r8837 > Wireless Signal Strength: 100% > > Problem: > Rebuffers after 22-23 seconds of playing an NPR MP3 Stream at: > http://www.opb.org/programs/streams/opb-radio.pls > > Question: > Is the Touch firmware supposed to be at 7.5.1-Rxxxx with a 7.6 server?
(In reply to comment #12) Confirmed: 100ms delay (off-sync) when syncing a SB Touch w/ latest firmware and a SB2/3/Classic. Does not occur with SB3 & SB2 synced. Version: 7.6.0 - r30936 @ Wed Jun 23 02:10:00 PDT 2010 Operating system: Windows 7 - EN - cp1252 Database Version: DBD::SQLite 1.29 (sqlite 3.6.22) Total Players Recognized: 4
I cannot reproduce this with 7.6 r9296. Do you still see it?
(In reply to comment #14) > I cannot reproduce this with 7.6 r9296. Do you still see it? Sorry, I can't reproduce it anymore, as I sold the Touch and replaced it with another SB3.
*** Bug 16653 has been marked as a duplicate of this bug. ***
== Auto-comment from SVN commit #31863 to the slim repo by ayoung == == http://svn.slimdevices.com/slim?view=revision&revision=31863 == bug 16233: mp3 stream with Xing header is handled wrong when proxied
Was able to Sync a classic and a touch and play various internet radio streams using the same provider (with the xing-lame header) 7.6.0.32390 classic FW 136