expectingtofly wrote: > "Force HTTP streaming" relates to the protocol used to get the chunked > audio from the BBC. So shouldn't relate to this issue. > "hide audio sample rate" relates to not setting the sample rate on the > track. That the trascode picker uses, Which also I don't expect to have > any impact (I have tried and it doesn't impact) > > To give you more info. I've captured a log with 2 extremes of > bufferThreshold set. Which is quite interesting. > > This is a log for a buffer of 1 second (40k) : > > > Code: -------------------- > > > Feb 28 16:49:58 squeezeplay: INFO audio.decode - Playback.lua:477 connect 172.16.0.8:9000 GET /stream.mp3?player=00:04:20:2c:fa:10 HTTP/1.0^M > Feb 28 16:49:58 squeezeplay: DEBUG audio.decode - Playback.lua:194 source=stream > Feb 28 16:49:58 squeezeplay: DEBUG audio.decode - stream_connectL:506 streambuf connect 172.16.0.8:9000 > Feb 28 16:49:58 squeezeplay: DEBUG audio.decode - Playback.lua:1262 stopping local pause timer > Feb 28 16:49:58 squeezeplay: DEBUG audio.decode - Playback.lua:1192 gainL, gainR: 555 555 > Feb 28 16:50:00 squeezeplay: DEBUG audio.decode - Playback.lua:397 resume decoder, 98304 bytes buffered, decode threshold 2048 > Feb 28 16:50:00 squeezeplay: DEBUG audio.decode - decode_resume_decoder:580 decode_resume_decoder > Feb 28 16:50:00 squeezeplay: DEBUG audio.decode - decode_resume_decoder_handler:122 resume_decoder decode state: 1 audio state 0 > Feb 28 16:50:00 squeezeplay: DEBUG audio.decode - debug_fullness:112 fullness: 98304 / 0 | 3.12% / 0.00% > Feb 28 16:50:00 squeezeplay: INFO audio.decode - Playback.lua:448 3.0%/0.0% > Feb 28 16:50:00 squeezeplay: DEBUG audio.decode - decode_output_samples:280 first buffer sample_rate=48000 > Feb 28 16:50:00 squeezeplay: DEBUG audio.decode - Playback.lua:424 resume audio bytesReceivedL=131072 outputTime=128 threshold=40960 > Feb 28 16:50:00 squeezeplay: DEBUG audio.decode - decode_resume_audio:601 decode_resume_audio start_jiffies=0 > Feb 28 16:50:00 squeezeplay: DEBUG audio.decode - decode_resume_audio_handler:133 decode_resume_audio_handler start_jiffies=0 > Feb 28 16:50:00 squeezeplay: DEBUG audio.decode - debug_fullness:112 fullness: 162224 / 65536 | 5.16% / 1.86% > Feb 28 16:50:00 squeezeplay: DEBUG audio.decode - decode_resume_audio_handler:146 resume_audio decode state: 1 audio state 40 > Feb 28 16:50:00 squeezeplay: DEBUG audio.decode - Playback.lua:381 status TRACK STARTED (elapsed: 42) > Feb 28 16:50:01 squeezeplay: INFO audio.decode - Playback.lua:448 15.5%/3.3% > Feb 28 16:50:02 squeezeplay: playback_callback:346 Audio underrun: used 160 frames, requested 480 frames. elapsed samples 86880 > Feb 28 16:50:02 squeezeplay: INFO audio.decode - Playback.lua:364 OUTPUT UNDERRUN > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - decode_pause_audio:624 decode_pause_audio interval_ms=0 > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - decode_pause_audio_handler:156 decode_pause_handler interval=0 > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - decode_pause_audio_handler:171 pause_audio decode state: 1 audio state 0 > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - Playback.lua:855 strm p > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - Playback.lua:1262 stopping local pause timer > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - decode_pause_audio:624 decode_pause_audio interval_ms=0 > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - decode_pause_audio_handler:156 decode_pause_handler interval=0 > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - decode_pause_audio_handler:171 pause_audio decode state: 1 audio state 0 > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - Playback.lua:1262 stopping local pause timer > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - Playback.lua:1192 gainL, gainR: 0 0 > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - Playback.lua:855 strm u > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - Playback.lua:991 resume unpause > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - decode_resume_audio:601 decode_resume_audio start_jiffies=0 > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - Playback.lua:1262 stopping local pause timer > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - Playback.lua:1192 gainL, gainR: 555 555 > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - decode_resume_audio_handler:133 decode_resume_audio_handler start_jiffies=0 > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - debug_fullness:112 fullness: 917712 / 94464 | 29.17% / 2.68% > Feb 28 16:50:02 squeezeplay: DEBUG audio.decode - decode_resume_audio_handler:146 resume_audio decode state: 1 audio state 40 > Feb 28 16:50:03 squeezeplay: INFO audio.decode - Playback.lua:448 35.8%/5.3% > > -------------------- > > > > Here's a log for the threshold set to 5 seconds (200k) : > > Code: -------------------- > > > Feb 28 16:52:12 squeezeplay: INFO audio.decode - Playback.lua:477 connect 172.16.0.8:9000 GET /stream.mp3?player=00:04:20:2c:fa:10 HTTP/1.0^M > Feb 28 16:52:12 squeezeplay: DEBUG audio.decode - Playback.lua:194 source=stream > Feb 28 16:52:12 squeezeplay: DEBUG audio.decode - stream_connectL:506 streambuf connect 172.16.0.8:9000 > Feb 28 16:52:12 squeezeplay: DEBUG audio.decode - Playback.lua:1262 stopping local pause timer > Feb 28 16:52:12 squeezeplay: DEBUG audio.decode - Playback.lua:1192 gainL, gainR: 555 555 > Feb 28 16:52:14 squeezeplay: DEBUG audio.decode - Playback.lua:397 resume decoder, 65536 bytes buffered, decode threshold 2048 > Feb 28 16:52:14 squeezeplay: DEBUG audio.decode - decode_resume_decoder:580 decode_resume_decoder > Feb 28 16:52:14 squeezeplay: DEBUG audio.decode - decode_resume_decoder_handler:122 resume_decoder decode state: 1 audio state 0 > Feb 28 16:52:14 squeezeplay: DEBUG audio.decode - debug_fullness:112 fullness: 65536 / 0 | 2.08% / 0.00% > Feb 28 16:52:14 squeezeplay: DEBUG audio.decode - decode_output_samples:280 first buffer sample_rate=48000 > Feb 28 16:52:14 squeezeplay: INFO audio.decode - Playback.lua:448 1.6%/0.7% > Feb 28 16:52:15 squeezeplay: DEBUG audio.decode - Playback.lua:424 resume audio bytesReceivedL=256440 outputTime=874 threshold=204800 > Feb 28 16:52:15 squeezeplay: DEBUG audio.decode - decode_resume_audio:601 decode_resume_audio start_jiffies=0 > Feb 28 16:52:15 squeezeplay: DEBUG audio.decode - decode_resume_audio_handler:133 decode_resume_audio_handler start_jiffies=0 > Feb 28 16:52:15 squeezeplay: DEBUG audio.decode - debug_fullness:112 fullness: 186808 / 352256 | 5.94% / 9.98% > Feb 28 16:52:15 squeezeplay: DEBUG audio.decode - decode_resume_audio_handler:146 resume_audio decode state: 1 audio state 40 > Feb 28 16:52:15 squeezeplay: DEBUG audio.decode - Playback.lua:381 status TRACK STARTED (elapsed: 175) > Feb 28 16:52:16 squeezeplay: INFO audio.decode - Playback.lua:448 15.9%/7.7% > Feb 28 16:52:17 squeezeplay: INFO audio.decode - Playback.lua:448 26.7%/5.4% > Feb 28 16:52:18 squeezeplay: INFO audio.decode - Playback.lua:448 32.9%/4.5% > Feb 28 16:52:19 squeezeplay: INFO audio.decode - Playback.lua:448 42.1%/2.8% > Feb 28 16:52:20 squeezeplay: playback_callback:346 Audio underrun: used 192 frames, requested 480 frames. elapsed samples 248640 > Feb 28 16:52:20 squeezeplay: playback_callback:346 Audio underrun: used 384 frames, requested 480 frames. elapsed samples 254592 > Feb 28 16:52:20 squeezeplay: INFO audio.decode - Playback.lua:364 OUTPUT UNDERRUN > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - decode_pause_audio:624 decode_pause_audio interval_ms=0 > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - decode_pause_audio_handler:156 decode_pause_handler interval=0 > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - decode_pause_audio_handler:171 pause_audio decode state: 1 audio state 0 > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - Playback.lua:855 strm p > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - Playback.lua:1262 stopping local pause timer > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - decode_pause_audio:624 decode_pause_audio interval_ms=0 > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - decode_pause_audio_handler:156 decode_pause_handler interval=0 > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - decode_pause_audio_handler:171 pause_audio decode state: 1 audio state 0 > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - Playback.lua:1262 stopping local pause timer > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - Playback.lua:1192 gainL, gainR: 0 0 > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - Playback.lua:855 strm u > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - Playback.lua:991 resume unpause > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - decode_resume_audio:601 decode_resume_audio start_jiffies=0 > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - Playback.lua:1262 stopping local pause timer > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - decode_resume_audio_handler:133 decode_resume_audio_handler start_jiffies=0 > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - debug_fullness:112 fullness: 1806764 / 86272 | 57.44% / 2.45% > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - Playback.lua:1192 gainL, gainR: 555 555 > Feb 28 16:52:20 squeezeplay: DEBUG audio.decode - decode_resume_audio_handler:146 resume_audio decode state: 1 audio state 40 > Feb 28 16:52:21 squeezeplay: INFO audio.decode - Playback.lua:448 64.4%/2.4% > -------------------- > > > > The underrun happens at the point of end of the Bufferthreshold time > that the buffer represents (1 second and 5 Second respectively) after > the track started . I guess that must mean something! But beats me > what that is :) That's what I noticed in the first log as well. To me, that means it's not making a difference and you can probably just remove setting the bufferThreshold.
It appears that at startup the player just can't fill the output buffer fast enough. Thanks for testing the different options. I now have a lot more info to go through. Ralphy *1*-Touch, *5*-Classics, *3*-Booms, *2*-UE Radio 'Squeezebox client builds' (https://sourceforge.net/projects/lmsclients/files/) 'donations' (https://www.paypal.com/cgi-bin/webscr?cmd=_donations&business=LL5P6365KQEXN&lc=CA&item_name=Squeezebox%20client%20builds¤cy_code=USD&bn=PP%2dDonationsBF%3abtn_donate_SM%2egif%3aNonHosted) always appreciated. ------------------------------------------------------------------------ ralphy's Profile: http://forums.slimdevices.com/member.php?userid=3484 View this thread: http://forums.slimdevices.com/showthread.php?t=113479 _______________________________________________ plugins mailing list plugins@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/plugins
