Re: [SlimDevices: SqueezeCenter] Which Log for capturing potential cause of buffering internet radio streams
garym wrote: > The word "buffering with percentage count up" shows upon the screen of > either the CONTROLLER or the SqueezePlay "screen" (I still use > squeezeplay as a controller on my windows laptop, controlling the > TRANSPORTER). Seems to be true buffering (as in, after rebuffering it > may pick up from exactly where it left off, as compared with a true > loss/gap in audio). > > A couple other points: > > 1. I get the buffering even when the Transporter and Radio are not > synced, and the Radio is not playing at all (but it is still connected > to the ethernet over power converters) > > 2. I don't get the buffering playing local files. Of course the > buffering is so intermittent* that I can't be 100% sure it doesn't > happen with local files, as I haven't tried that for an all day period. "Buffering" will appear when a player reports to LMS that it has no data to play in its buffer (can't remember which buffer "undecoded" or "decoded"). When a player is synced the audio stream will go through LMS but when a player is not synced - the stream may be played directly by the player - if conditions are right. If, for test purposes, you can play a stream directly by the player (i.e audio goes straight from Station to player - not through LMS) and no "Buffering" occurs then it is likely LMS can be considered part of the problem. If when playing directly "buffering" still appears -then "network" is the problem. As Transporter cannot play AAC natively and no older SB player can handle HTTPS - a test stream has to be a HTTP/MP3 stream with no redirection to HTTPS. LMS setting also important (before changing, please record and report the current settings for reference) - the player must be unsynced - WebUI Settings/Player/Audio/Streaming method is set to "Direct Streaming" - WebUI Settings/Advanced/Network/Streaming mode for HTTPS is set to "Normal" - WebUI Settings/Advanced/Filetypes MP3 - Native To confirm playing the stream a test run can be done using player.source set to INFO to confirm that stream is being played direct. As a further check on network health for unusual items such as errors, timeouts, retransmissions etc.. I don't know PCP that well so there may be a btter command. Can you post a dump before and after a test of /proc/net/netstat The output can be made pretty later. bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806 View this thread: http://forums.slimdevices.com/showthread.php?t=116117 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] Which Log for capturing potential cause of buffering internet radio streams
garym wrote: > *by intermittent, I mean that it may go many hours without buffering. > But when it does start buffering, it may buffer frequently over a short > window (every few minutes over a 30 minute window). In the past, I > would also notice very low UPLOAD speed at the same time, but normal > DOWNLOAD speed). Separate line of inquiry. Can you log into ISP modem : - What does modem say about "link to ISP" quality ? Is it different to "normal" times ? - look at line statistics ? Is there any unusual data activity happening at this time (e.g. if using a cable service could DVR be sending data upload) somewhere on network. bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806 View this thread: http://forums.slimdevices.com/showthread.php?t=116117 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] Which Log for capturing potential cause of buffering internet radio streams
As Transporter cannot play AAC natively and no older SB player can handle HTTPS - a test stream has to be a HTTP/MP3 stream with no redirection to HTTPS. PLAYING MP3, HTTP STREAM: HTTP://AM820.WNYC.ORG/WNYCAM [/B] LMS SETTING ALSO IMPORTANT (BEFORE CHANGING, PLEASE RECORD AND REPORT THE CURRENT SETTINGS FOR REFERENCE) - THE PLAYER MUST BE UNSYNCED *CURRENTLY UNSYNCHED, HAVE TESTED BOTH WAYS * - WEBUI SETTINGS/PLAYER/AUDIO/STREAMING METHOD IS SET TO \"DIRECT STREAMING\" *WAS PROXIED STREAMING BUT NOW SET TO \"DIRECT STREAMING\"* - WEBUI SETTINGS/ADVANCED/NETWORK/STREAMING MODE FOR HTTPS IS SET TO \"NORMAL\" *WAS PERSISTENT NOW SET TO NORMAL.* - WEBUI SETTINGS/ADVANCED/FILETYPES MP3 - NATIVE *ALWAYS SET THIS WAY To confirm playing the stream a test run can be done using player.source set to INFO to confirm that stream is being played direct. [B]Odd that with this set to INFO, I get almost nothing on the server log. See attached. In fact, nothing at all showing from this morning, March 22, 2022, post 7:00am. Logging settings: 37535 https://www.dropbox.com/s/pz1zhancxcqp4vo/server.log?dl=0 *As a further check on network health for unusual items such as errors, timeouts, retransmissions etc.. I don't know PCP that well so there may be a btter command. Can you post a dump before and after a test of /proc/net/netstat The output can be made pretty later. *the current dump, with no problems happening: https://www.dropbox.com/s/ifxyxfehozysg83/netstat_beforeProblem?dl=0 * edit: What is the current value for WebUI Settings/Advanced/Network Radio Station buffer seconds. *15, had been 3, but I increased to 15, and still get the rebuffering occasionally * +---+ |Filename: Capture.JPG | |Download: http://forums.slimdevices.com/attachment.php?attachmentid=37535| +---+ *Home:* Pi4B-8GB/pCP8.x/4TB>LMS 8.2.x>Transporter, Touch, Boom, Radio (all ethernet) *Cottage:* rPi4B-4GB/pCP8.x/4TB>LMS 8.2.x>Touch>Benchmark DAC I, Boom, Radio w/Battery (Radio WIFI) *Office:* Win10(64)>foobar2000 *The Wild: *rPi3B+/pCP7.x/4TB>LMS 8.1.x>hifiberry Dac+Pro (LMS & Squeezelite) *Controllers:* iPhone11 & iPadAir3 (iPeng), CONTROLLER, Material Skin, or SqueezePlay 7.8 on Win10(64) *Files:* -Ripping-: dBpoweramp > FLAC; -Post-rip-: mp3tag, PerfectTunes, TuneFusion; -Streaming:- Spotify garym's Profile: http://forums.slimdevices.com/member.php?userid=17325 View this thread: http://forums.slimdevices.com/showthread.php?t=116117 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] Which Log for capturing potential cause of buffering internet radio streams
bpa wrote: > Separate line of inquiry. > > Can you log into ISP modem : > - What does modem say about "link to ISP" quality ? Is it different to > "normal" times ? > - look at line statistics ? Is there any unusual data activity happening > at this time (e.g. if using a cable service could DVR be sending data > upload) somewhere on network. I can login to ISP modem. there is no item "quality", but all the connections report OK, and there is nothing odd reported. Up time is 8 days (I rebooted modem then). See pic: 37538 +---+ |Filename: Capture2.JPG | |Download: http://forums.slimdevices.com/attachment.php?attachmentid=37538| +---+ *Home:* Pi4B-8GB/pCP8.x/4TB>LMS 8.2.x>Transporter, Touch, Boom, Radio (all ethernet) *Cottage:* rPi4B-4GB/pCP8.x/4TB>LMS 8.2.x>Touch>Benchmark DAC I, Boom, Radio w/Battery (Radio WIFI) *Office:* Win10(64)>foobar2000 *The Wild: *rPi3B+/pCP7.x/4TB>LMS 8.1.x>hifiberry Dac+Pro (LMS & Squeezelite) *Controllers:* iPhone11 & iPadAir3 (iPeng), CONTROLLER, Material Skin, or SqueezePlay 7.8 on Win10(64) *Files:* -Ripping-: dBpoweramp > FLAC; -Post-rip-: mp3tag, PerfectTunes, TuneFusion; -Streaming:- Spotify garym's Profile: http://forums.slimdevices.com/member.php?userid=17325 View this thread: http://forums.slimdevices.com/showthread.php?t=116117 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] Which Log for capturing potential cause of buffering internet radio streams
garym wrote: > I can login to ISP modem. there is no item "quality", but all the > connections report OK, and there is nothing odd reported. Up time is 8 > days (I rebooted modem then). See pic: > > 37538 It may take a bit of diugging. Is there no Admin menu ? possibly with Network Tools. My Virgin Modem has the following under Admin/Advanced/Tools/Network Status - Configuration and network Log. At least I can see what is configured at the time. Code: Refresh data General Configuration Network accessAllowed Maximum Number of CPEs10 Baseline Privacy Enabled DOCSIS Mode DOCSIS 3.0 Config file CH7465LG_cm_res007_v4-sip.bin Primary Downstream Service Flow SFID 898064410 Max Traffic Rate 10485760 bps Max Traffic Burst 16320 bytes Min Traffic Rate 0 bps SFID 898064409 Max Traffic Rate 16 bps Max Traffic Burst 3044 bytes Min Traffic Rate 12000 bps SFID 898064408 Max Traffic Rate 53500 bps Max Traffic Burst 42600 bytes Min Traffic Rate 0 bps Primary Upstream Service Flow SFID 898056220 Max Traffic Rate 2097152 bps Max Traffic Burst 16320 bytes Min Traffic Rate 0 bps Max Concatenated Burst16320 bytes Scheduling Type Best Effort SFID 898056219 Max Traffic Rate 16 bps Max Traffic Burst 3044 bytes Min Traffic Rate 12000 bps Max Concatenated Burst1522 bytes Scheduling Type Best Effort SFID 898056215 Max Traffic Rate 5350 bps Max Traffic Burst 42600 bytes Min Traffic Rate 0 bps Max Concatenated Burst42600 bytes Scheduling Type Best Effort bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806 View this thread: http://forums.slimdevices.com/showthread.php?t=116117 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] Which Log for capturing potential cause of buffering internet radio streams
bpa wrote: > It may take a bit of digging. Is there no Admin menu ? possibly with > Network Tools. My Virgin Modem has the following under > Admin/Advanced/Tools/Network Status - Configuration and network Log. At > least I can see what is configured at the time. > > Code: > > > Refresh data > General Configuration > Network accessAllowed > Maximum Number of CPEs10 > Baseline PrivacyEnabled > DOCSIS ModeDOCSIS 3.0 > Config fileCH7465LG_cm_res007_v4-sip.bin > > Primary Downstream Service Flow > SFID898064410 > Max Traffic Rate10485760 bps > Max Traffic Burst16320 bytes > Min Traffic Rate0 bps > SFID898064409 > Max Traffic Rate16 bps > Max Traffic Burst3044 bytes > Min Traffic Rate12000 bps > SFID898064408 > Max Traffic Rate53500 bps > Max Traffic Burst42600 bytes > Min Traffic Rate0 bps > > Primary Upstream Service Flow > SFID898056220 > Max Traffic Rate2097152 bps > Max Traffic Burst16320 bytes > Min Traffic Rate0 bps > Max Concatenated Burst16320 bytes > Scheduling TypeBest Effort > SFID898056219 > Max Traffic Rate16 bps > Max Traffic Burst3044 bytes > Min Traffic Rate12000 bps > Max Concatenated Burst1522 bytes > Scheduling TypeBest Effort > SFID898056215 > Max Traffic Rate5350 bps > Max Traffic Burst42600 bytes > Min Traffic Rate0 bps > Max Concatenated Burst42600 bytes > Scheduling TypeBest Effort > > > unfortunately, no options like this at all, and I've checked every menu. Even though I own the modem, the ISP, Cox Cable, keeps things pretty locked down. p.s. regarding other activity (DVR), I don't use DVR or regular Cable TV. And wasn't uploading or downloading files on network when having buffering. *Home:* Pi4B-8GB/pCP8.x/4TB>LMS 8.2.x>Transporter, Touch, Boom, Radio (all ethernet) *Cottage:* rPi4B-4GB/pCP8.x/4TB>LMS 8.2.x>Touch>Benchmark DAC I, Boom, Radio w/Battery (Radio WIFI) *Office:* Win10(64)>foobar2000 *The Wild: *rPi3B+/pCP7.x/4TB>LMS 8.1.x>hifiberry Dac+Pro (LMS & Squeezelite) *Controllers:* iPhone11 & iPadAir3 (iPeng), CONTROLLER, Material Skin, or SqueezePlay 7.8 on Win10(64) *Files:* -Ripping-: dBpoweramp > FLAC; -Post-rip-: mp3tag, PerfectTunes, TuneFusion; -Streaming:- Spotify garym's Profile: http://forums.slimdevices.com/member.php?userid=17325 View this thread: http://forums.slimdevices.com/showthread.php?t=116117 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] Which Log for capturing potential cause of buffering internet radio streams
I set player.source to debug and I do now get info. Not clear that it is telling me that I am getting direct streaming of mp3/http. attached +---+ |Filename: server.log | |Download: http://forums.slimdevices.com/attachment.php?attachmentid=37539| +---+ *Home:* Pi4B-8GB/pCP8.x/4TB>LMS 8.2.x>Transporter, Touch, Boom, Radio (all ethernet) *Cottage:* rPi4B-4GB/pCP8.x/4TB>LMS 8.2.x>Touch>Benchmark DAC I, Boom, Radio w/Battery (Radio WIFI) *Office:* Win10(64)>foobar2000 *The Wild: *rPi3B+/pCP7.x/4TB>LMS 8.1.x>hifiberry Dac+Pro (LMS & Squeezelite) *Controllers:* iPhone11 & iPadAir3 (iPeng), CONTROLLER, Material Skin, or SqueezePlay 7.8 on Win10(64) *Files:* -Ripping-: dBpoweramp > FLAC; -Post-rip-: mp3tag, PerfectTunes, TuneFusion; -Streaming:- Spotify garym's Profile: http://forums.slimdevices.com/member.php?userid=17325 View this thread: http://forums.slimdevices.com/showthread.php?t=116117 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] Which Log for capturing potential cause of buffering internet radio streams
garym wrote: > [B]Odd that with this set to INFO, I get almost nothing on the server > log. See attached. In fact, nothing at all showing from this morning, > March 22, 2022, post 7:00am. Something odd with your logging. Perhaps didn't click Apply. The log should look something like below. I've highlighted the key log entry to show direct streaming. I don't like the look that your system is trying to download a firmware update but fails. That may cause problem if it retries at various periods. Code: [22-03-22 12:32:53.9761] Slim::Player::StreamingController::_setPlayingState (2380) new playing state STOPPED [22-03-22 12:32:53.9762] Slim::Player::StreamingController::_setStreamingState (2389) new streaming state IDLE [22-03-22 12:32:53.9765] Slim::Player::StreamingController::resetSongqueue (1799) Song queue is now [22-03-22 12:32:53.9772] Slim::Player::StreamingController::play (2123) 00:04:20:16:07:0e [22-03-22 12:32:53.9776] Slim::Player::StreamingController::_setPlayingState (2380) new playing state STOPPED [22-03-22 12:32:53.9777] Slim::Player::StreamingController::_setStreamingState (2389) new streaming state IDLE [22-03-22 12:32:53.9787] Slim::Player::Song::new (109) index 0 -> http://am820.wnyc.org/wnycam [22-03-22 12:32:53.9792] Slim::Player::StreamingController::_setStreamingState (2389) new streaming state TRACKWAIT [22-03-22 12:32:53.9816] Slim::Player::StreamingController::_playersMessage (799) Getting stream info...: http://am820.wnyc.org/wnycam [22-03-22 12:32:53.9821] Slim::Player::Song::getNextSong (222) http://am820.wnyc.org/wnycam [22-03-22 12:32:53.9823] Slim::Player::Song::getNextSong (244) scanning URL http://am820.wnyc.org/wnycam [22-03-22 12:32:55.1658] Slim::Player::Song::getNextSong (222) http://am820.wnyc.org/wnycam [22-03-22 12:32:55.1664] Slim::Player::StreamingController::_nextTrackReady (747) 00:04:20:16:07:0e: nextTrack will be index 0 [22-03-22 12:32:55.1668] Slim::Player::StreamingController::_Stream (1213) Song queue is now 0 [22-03-22 12:32:55.1671] Slim::Player::StreamingController::_Stream (1216) 00:04:20:16:07:0e: preparing to stream song index 0 [22-03-22 12:32:55.1674] Slim::Player::Song::open (362) http://am820.wnyc.org/wnycam [22-03-22 12:32:55.1695] Slim::Player::TranscodingHelper::getConvertCommand2 (490) Error: Didn't find any command matches for type: mp3 [22-03-22 12:32:55.1698] Slim::Player::Song::open (386) seek=false time=0 canSeek=0SEEK_ERROR_MP3_UNKNOWN_DURATION [22-03-22 12:32:55.1705] Slim::Player::TranscodingHelper::getConvertCommand2 (493) Matched: mp3->mp3 via: - [22-03-22 12:32:55.1708] Slim::Player::Song::open (418) Transcoder: streamMode=I, streamformat=mp3 [22-03-22 12:32:55.1713] Slim::Player::Song::open (464) URL supports direct streaming [http://am820.wnyc.org/wnycam->http://am820.wnyc.org/wnycam] [22-03-22 12:32:55.1912] Slim::Player::StreamingController::_Stream (1285) 00:04:20:16:07:0e: stream [22-03-22 12:32:55.1934] Slim::Player::StreamingController::_Stream (1322) Song queue is now 0 [22-03-22 12:32:55.1935] Slim::Player::StreamingController::_setPlayingState (2380) new playing state BUFFERING [22-03-22 12:32:55.1937] Slim::Player::StreamingController::_setStreamingState (2389) new streaming state STREAMING [22-03-22 12:32:55.3177] Slim::Player::Player::_buffering (1144) Buffering... 0 / 36864 [22-03-22 12:32:55.5364] Slim::Player::TranscodingHelper::getConvertCommand2 (490) Error: Didn't find any command matches for type: mp3 [22-03-22 12:32:55.6183] Slim::Player::Player::_buffering (1144) Buffering... 0 / 36864 [22-03-22 12:32:55.9193] Slim::Player::Player::_buffering (1144) Buffering... 0 / 36864 [22-03-22 12:32:56.2202] Slim::Player::Player::_buffering (1144) Buffering... 0 / 36864 [22-03-22 12:32:56.5214] Slim::Player::Player::_buffering (1144) Buffering... 16972 / 36864 [22-03-22 12:32:56.5742] Slim::Player::StreamingController::playerTrackStarted (2203) 00:04:20:16:07:0e [22-03-22 12:32:56.5746] Slim::Player::StreamingController::_setPlayingState (2380) new playing state PLAYING [22-03-22 12:32:56.5750] Slim::Player::StreamingController::_Playing (368) Song 0 has now started playing [22-03-22 12:32:56.5758] Slim::Player::StreamingController::_Playing (397) Song queue is now 0 [22-03-22 12:33:00.5916] Slim::Player::TranscodingHelper::getConvertCommand2 (490) Error: Didn't find any command matches for type: mp3 [22-03-22 12:33:08.7198] Slim::Player::StreamingController::stop (2120) 00:04:20:16:07:0e [22-03-22 12:33:08.7204] Slim::Player::StreamingController::_Stop (610) Song queue is now 0 [22-03-22 12:33:08.7207] Slim::Player::StreamingController::_setPlayingState (2380) new playing state STOPPED [22-03-22 12:33:08.7208] Slim::Player::StreamingController::_setStreamingState (2389) new streaming state IDLE [22-03-22 12:33:08.7211] Slim::Player::StreamingController::rese
Re: [SlimDevices: SqueezeCenter] Which Log for capturing potential cause of buffering internet radio streams
garym wrote: > What is the current value for WebUI Settings/Advanced/Network Radio > Station buffer seconds. *15, had been 3, but I increased to 15, and still get the rebuffering occasionally * This setting is the initial buffer size in seconds - effectively it is how much audio data should be in player buffer before LMS allows station to start playing. However once data in the player buffer is depleted (i.e. buffering message appears after radio has been playing for a while) - the setting has no function. If the setting is initially too small, then you can get buffering shortly after playing starts and repeats - this can happen with high data rate streams (i.e not enough time to fill player buffer before all buffered data is played) 15 secs is reasonable value,and streams are "normal" - so a "too small number" is probably not the cause. bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806 View this thread: http://forums.slimdevices.com/showthread.php?t=116117 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] Which Log for capturing potential cause of buffering internet radio streams
bpa wrote: > Something odd with your logging. Perhaps didn't click Apply. The log > should look something like below. I've highlighted the key log entry to > show direct streaming. > I don't like the look that your system is trying to download a firmware > update but fails. That may cause problem if it retries at various > periods. > > I've rebooted rPi with LMS and started playing again. With info, I now > see the playing of the radio stream in the log (and showing it is > direct). But what is this error about mp3. That seems odd. mp3 is set > to "native" in filetypes.Excerpt here: > > [22-03-22 09:01:16.6438] Slim::Player::Song::open (386) seek=false > time=0 canSeek=0SEEK_ERROR_TYPE_NOT_SUPPORTED > [22-03-22 09:01:16.6458] > Slim::Player::TranscodingHelper::getConvertCommand2 (493) Matched: > mp3->mp3 via: - > [22-03-22 09:01:16.6464] Slim::Player::Song::open (416) Transcoder: > streamMode=I, streamformat=mp3 > *[22-03-22 09:01:16.6473] Slim::Player::Song::open (462) URL supports > direct streaming > [http://am820.wnyc.org/wnycam->http://am820.wnyc.org/wnycam]* > [22-03-22 09:01:16.6725] Slim::Player::StreamingController::_Stream > (1282) 00:04:20:10:12:97: stream > [22-03-22 09:01:16.6738] Slim::Player::Transporter::setDigitalInput > (188) Switching to digital input 0 > [22-03-22 09:01:16.6840] Slim::Player::StreamingController::_Stream > (1319) Song queue is now 0 > [22-03-22 09:01:16.6845] > Slim::Player::StreamingController::_setPlayingState (2377) new playing > state BUFFERING > [22-03-22 09:01:16.6847] > Slim::Player::StreamingController::_setStreamingState (2386) new > streaming state STREAMING > [22-03-22 09:01:16.8047] Slim::Player::Player::_buffering (1144) > Buffering... 0 / 184320 > [22-03-22 09:01:16.8053] Slim::Player::Player::_buffering (1145) > +output... 3519672 / 5292000 > *[22-03-22 09:01:16.8156] > Slim::Player::TranscodingHelper::getConvertCommand2 (490) Error: Didn't > find any command matches for type: mp3 > > *full log: +---+ |Filename: server.log | |Download: http://forums.slimdevices.com/attachment.php?attachmentid=37540| +---+ *Home:* Pi4B-8GB/pCP8.x/4TB>LMS 8.2.x>Transporter, Touch, Boom, Radio (all ethernet) *Cottage:* rPi4B-4GB/pCP8.x/4TB>LMS 8.2.x>Touch>Benchmark DAC I, Boom, Radio w/Battery (Radio WIFI) *Office:* Win10(64)>foobar2000 *The Wild: *rPi3B+/pCP7.x/4TB>LMS 8.1.x>hifiberry Dac+Pro (LMS & Squeezelite) *Controllers:* iPhone11 & iPadAir3 (iPeng), CONTROLLER, Material Skin, or SqueezePlay 7.8 on Win10(64) *Files:* -Ripping-: dBpoweramp > FLAC; -Post-rip-: mp3tag, PerfectTunes, TuneFusion; -Streaming:- Spotify garym's Profile: http://forums.slimdevices.com/member.php?userid=17325 View this thread: http://forums.slimdevices.com/showthread.php?t=116117 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] Which Log for capturing potential cause of buffering internet radio streams
bpa wrote: > This setting is the initial buffer size in seconds - effectively it is > how much audio data should be in player buffer before LMS allows station > to start playing. However once data in the player buffer is depleted > (i.e. buffering message appears after radio has been playing for a > while) - the setting has no function. > If the setting is initially too small, then you can get buffering > shortly after playing starts and repeats - this can happen with high > data rate streams (i.e not enough time to fill player buffer before all > buffered data is played) > 15 secs is reasonable value,and streams are "normal" - so a "too small > number" is probably not the cause. understand. thanks. Makes sense as either 3 or 15 didn't really affect the rebuffering issue (15 simply makes it take a bit longer to start the stream, of course) *Home:* Pi4B-8GB/pCP8.x/4TB>LMS 8.2.x>Transporter, Touch, Boom, Radio (all ethernet) *Cottage:* rPi4B-4GB/pCP8.x/4TB>LMS 8.2.x>Touch>Benchmark DAC I, Boom, Radio w/Battery (Radio WIFI) *Office:* Win10(64)>foobar2000 *The Wild: *rPi3B+/pCP7.x/4TB>LMS 8.1.x>hifiberry Dac+Pro (LMS & Squeezelite) *Controllers:* iPhone11 & iPadAir3 (iPeng), CONTROLLER, Material Skin, or SqueezePlay 7.8 on Win10(64) *Files:* -Ripping-: dBpoweramp > FLAC; -Post-rip-: mp3tag, PerfectTunes, TuneFusion; -Streaming:- Spotify garym's Profile: http://forums.slimdevices.com/member.php?userid=17325 View this thread: http://forums.slimdevices.com/showthread.php?t=116117 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] Which Log for capturing potential cause of buffering internet radio streams
garym wrote: > I've rebooted rPi with LMS and started playing again. With info, I now > see the playing of the radio stream in the log (and showing it is > direct). But what is this error about mp3. That seems odd. mp3 is set > to "native" in filetypes. How LMS evaluates formats and transcoding options can confuse. My knowledge is not fully up to fate since changes in 8.? which include the "File conversion format setup" check box but I'll give a brief summary. When an audio source is about to be played LMS evaluates its characteristics again all those available in FileTypes. Factor include source audio codec, destination supported codecs, source type (e.g. remote HTTP, remote HTTPS, file), bit rate vs player support bitrate etc. *ALL* the various rules are effectively evaluated in parallel. Ones that are not successful are rejected, successes are remembered as candidates - I think the logging process will log the rejection but not all the successes. When all rules have been evaluated - the "best" one is chosen - simplistically the ordering of "best" is: direct vs indirect, native vs transcoded, transcoded lossless vs lossy - but some setting can override these (e.g. "File conversion format setup"). I think evaluations are done via "callbacks" so sometimes the log message will appear well after the evaluation has completed and is not really contemporary. In your log. The "New state STREAMING" indicates the player has issued a HTTP/GET and player is getting data direct from the station. Player regularly report back to LMS it status and the status contains buffer fullness. The logging is showing two number - the amount of data in the input buffer and the threshold (184320) that must be reach before playing starts - threshold value is LMS calculation of 15 secs of audio based on a preview of audio data. A delayed log message of the evaluation of the rules appears - it is stating that one of the rules was evaluated and rejected - but it may be hard to understand but this rejection happened before the player streaming GET has started. This occurs in 150ms. I don't worry about "why", I now know this is "normal" for a log of transcoding but it is a source of confusion for some users who may try to "fix" the problem not realising it is not an error. Code: [22-03-22 09:01:16.6847] Slim::Player::StreamingController::_setStreamingState (2386) new streaming state STREAMING [22-03-22 09:01:16.8047] Slim::Player::Player::_buffering (1144) Buffering... 0 / 184320 [22-03-22 09:01:16.8053] Slim::Player::Player::_buffering (1145) +output... 3519672 / 5292000 [22-03-22 09:01:16.8156] Slim::Player::TranscodingHelper::getConvertCommand2 (490) Error: Didn't find any command matches for type: mp3 [22-03-22 09:01:17.1097] Slim::Player::Player::_buffering (1144) Buffering... 0 / 184320 [22-03-22 09:01:17.4140] Slim::Player::Player::_buffering (1144) Buffering... 0 / 184320 [22-03-22 09:01:17.7179] Slim::Player::Player::_buffering (1144) Buffering... 0 / 184320 [22-03-22 09:01:18.0212] Slim::Player::Player::_buffering (1144) Buffering... 34968 / 184320 [22-03-22 09:01:18.3247] Slim::Player::Player::_buffering (1144) Buffering... 74422 / 184320 [22-03-22 09:01:18.6284] Slim::Player::Player::_buffering (1144) Buffering... 120096 / 184320 . . [22-03-22 09:01:23.1875] Slim::Player::Player::_buffering (1144) Buffering... 182304 / 184320 [22-03-22 09:01:23.2778] Slim::Player::StreamingController::playerTrackStarted (2200) 00:04:20:10:12:97 [22-03-22 09:01:23.2784] Slim::Player::StreamingController::_setPlayingState (2377) new playing state PLAYING Input buffer got more data until threshold of 184320 must have been breached at around 22-03-22 09:01:23.2778 and so playing can then start. bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806 View this thread: http://forums.slimdevices.com/showthread.php?t=116117 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] Which Log for capturing potential cause of buffering internet radio streams
thanks for the analysis. I'll run this setup for a while and wait for a problem to occur. thanks so much for your detailed responses and help. *Home:* Pi4B-8GB/pCP8.x/4TB>LMS 8.2.x>Transporter, Touch, Boom, Radio (all ethernet) *Cottage:* rPi4B-4GB/pCP8.x/4TB>LMS 8.2.x>Touch>Benchmark DAC I, Boom, Radio w/Battery (Radio WIFI) *Office:* Win10(64)>foobar2000 *The Wild: *rPi3B+/pCP7.x/4TB>LMS 8.1.x>hifiberry Dac+Pro (LMS & Squeezelite) *Controllers:* iPhone11 & iPadAir3 (iPeng), CONTROLLER, Material Skin, or SqueezePlay 7.8 on Win10(64) *Files:* -Ripping-: dBpoweramp > FLAC; -Post-rip-: mp3tag, PerfectTunes, TuneFusion; -Streaming:- Spotify garym's Profile: http://forums.slimdevices.com/member.php?userid=17325 View this thread: http://forums.slimdevices.com/showthread.php?t=116117 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] [FreeBSD/XigmaNAS/TrueNAS] LogitechMediaServer Installation
So I upgraded my spotty plugin and noticed my scan is failing during the
spotty portion of the scan? It appears as if the there is now an issue
with the Spotty Helper application? the helper does appear to be there
in the plugin section. Would you have any ideas? I may try
unchecking/rechecking the helper plugin to see if that helps.
[22-03-22 10:52:29.4871] Slim::Utils::Scanner::Local::new (905) Handling
new playlist file:///mnt/media/LMS/Playlist/randommk1.m3u
[22-03-22 10:52:29.5180] Slim::Utils::Scanner::Local::__ANON__ (381)
Rescanning changed audio files (0)
[22-03-22 10:52:29.5183] Slim::Music::Import::endImporter (711)
Completed Slim::Music::PlaylistFolderScan Scan in 3.341 seconds.
[22-03-22 10:52:29.5185] Slim::Music::Import::runImporter (578) Starting
Plugins::Spotty::Importer scan
[22-03-22 10:52:29.5264] Plugins::Spotty::Helper::get (51) Didn't find
Spotty helper application!
[22-03-22 10:52:29.5521] Plugins::Spotty::API::Token::_gotTokenInfo
(153) Failed to get Spotify access token: malformed JSON string, neither
tag, array, object, number, string or atom, at character offset 0
(before "sh: : Permission den...") at
/usr/local/share/logitechmediaserver/Cache/InstalledPlugins/Plugins/Spotty/API/Token.pm
line 150.
sh: : Permission denied
[22-03-22 10:52:29.5526] main::main (338) Error: Failed when running
main scan: [Can't use string ("sh: : Permission denied
") as a HASH ref while "strict refs" in use at
/usr/local/share/logitechmediaserver/Cache/InstalledPlugins/Plugins/Spotty/API/Token.pm
line 168.
]
[22-03-22 10:52:29.5527] main::main (339) Error: Skipping post-process &
Not updating lastRescanTime!
HOME OFFICE
SB2->Benchmark DAC-1-> Bryston P-25, preamp -> Carver M1.0t Amp->PMC
TB2
HOME THEATER SYSTEM#1
SB2->Anthem AVM60->Bryston 9B ST -> PSB Stratus Goldi
/HOME THEATER SYSTEM #2/ LAZYEYE BAR
Pi3 w/7" screen/HiFiBerry DAC>Outlaw 976-> Bryston 3B ->Klipsch La
Scala's, 2x Bryston 4B (mono) EV 18" subwoofers
BEDROOM SYSTEM
SB2-> Sony BoomBox
REAR DECK/PATIO
Pi3 HiFiBerry DAC --> Crown XLS 1500-> PSB Mini's,
KITCHEN
Pi3 HifiBerry DAC --> Crown XLS 2502-> Polk Ceiling Speakers
sfraser's Profile: http://forums.slimdevices.com/member.php?userid=2026
View this thread: http://forums.slimdevices.com/showthread.php?t=113909
___
Squeezecenter mailing list
Squeezecenter@lists.slimdevices.com
http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] [FreeBSD/XigmaNAS/TrueNAS] LogitechMediaServer Installation
[22-03-22 10:52:29.5264] Plugins::Spotty::Helper::get (51) Didn't find Spotty helper application! Spotty doesn't have helpers for *BSD built in. You'd have to either try to use the Spotty BSD plugin somebody is providing. But that's an outdated version of the spotty helper. Or you try to build it yourself from the source (which should be pretty straight forward, but might require installation of Rust). https://github.com/michaelherger/librespot ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] Which Log for capturing potential cause of buffering internet radio streams
garym wrote: > thanks for the analysis. I'll run this setup for a while and wait for a > problem to occur. thanks so much for your detailed responses and help. The display during buffering with the percentage bothered me (i.e. was the Preference setting involved - in your case 15 secs). So I just checked the code and AFAICT the percentage is of a fixed number 5 secs of 44.1kHz 2 channel 32bits/sample audio. Also it looks like that if player.source is set to INFO - it may log all occurances of "Buffering" - it may be useful if you want to run a test unattended. bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806 View this thread: http://forums.slimdevices.com/showthread.php?t=116117 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] Which Log for capturing potential cause of buffering internet radio streams
bpa wrote: > The display during buffering with the percentage bothered me (i.e. was > the Preference setting involved - in your case 15 secs). So I just > checked the code and AFAICT the percentage is of a fixed number 5 secs > of 44.1kHz 2 channel 32bits/sample audio in the output buffer. > > Also it looks like that if player.source is set to INFO - it may log all > occurances of "Buffering" - it may be useful if you want to run a test > unattended. Thanks, I'll leave it on INFO with the settings (direct streaming, etc.) as changed this morning and let it run all day. Of course, since this morning, I've had zero issues. p.s. Yes, the display during rebuffering is: Rebuffering 0%...4%35%.68% (just making up the numbers, and it only shows one number at time). And then before it reaches 100% it always just starts playing (with the rebuffering info gone). *Home:* Pi4B-8GB/pCP8.x/4TB>LMS 8.2.x>Transporter, Touch, Boom, Radio (all ethernet) *Cottage:* rPi4B-4GB/pCP8.x/4TB>LMS 8.2.x>Touch>Benchmark DAC I, Boom, Radio w/Battery (Radio WIFI) *Office:* Win10(64)>foobar2000 *The Wild: *rPi3B+/pCP7.x/4TB>LMS 8.1.x>hifiberry Dac+Pro (LMS & Squeezelite) *Controllers:* iPhone11 & iPadAir3 (iPeng), CONTROLLER, Material Skin, or SqueezePlay 7.8 on Win10(64) *Files:* -Ripping-: dBpoweramp > FLAC; -Post-rip-: mp3tag, PerfectTunes, TuneFusion; -Streaming:- Spotify garym's Profile: http://forums.slimdevices.com/member.php?userid=17325 View this thread: http://forums.slimdevices.com/showthread.php?t=116117 ___ Squeezecenter mailing list Squeezecenter@lists.slimdevices.com http://lists.slimdevices.com/mailman/listinfo/squeezecenter
Re: [SlimDevices: SqueezeCenter] Which Log for capturing potential cause of buffering internet radio streams
Finally had one of these rebuffering episodes (not synched, direct playback to player, etc.). Was fine for several hours through 17:11 time. Then at 19:18 time (excerpt below), it stopped and then rebuffered before starting back playing. Note the "playerOutputUnderrun" message when this started. (full log at end of message). Code: *[22-03-22 19:18:22.4027] Slim::Player::StreamingController::playerOutputUnderrun (2239) 00:04:20:10:12:97: decoder: 150 / output: 0* [22-03-22 19:18:22.4034] Slim::Player::StreamingController::_setPlayingState (2377) new playing state BUFFERING [22-03-22 19:18:22.5346] Slim::Player::Player::_buffering (1144) Buffering... 150 / 8 [22-03-22 19:18:22.8377] Slim::Player::Player::_buffering (1144) Buffering... 150 / 8 [...] buffering lines removed [22-03-22 19:18:51.7637] Slim::Player::Player::_buffering (1144) Buffering... 3069 / 8 [22-03-22 19:18:52.0678] Slim::Player::Player::_buffering (1144) Buffering... 3069 / 8 [22-03-22 19:18:52.3718] Slim::Player::Player::_buffering (1144) Buffering... 3069 / 8 [22-03-22 19:18:52.6753] Slim::Player::Player::_buffering (1144) Buffering... 3069 / 8 [22-03-22 19:18:52.9792] Slim::Player::Player::_buffering (1144) Buffering... 3069 / 8 [22-03-22 19:18:53.2837] Slim::Player::StreamingController::jumpToTime (2166) 00:04:20:10:12:97 [22-03-22 19:18:53.2860] Slim::Player::StreamingController::_Stop (610) Song queue is now 0 [22-03-22 19:18:53.2867] Slim::Player::StreamingController::_setPlayingState (2377) new playing state STOPPED [22-03-22 19:18:53.2871] Slim::Player::StreamingController::_setStreamingState (2386) new streaming state IDLE [22-03-22 19:18:53.2877] Slim::Player::StreamingController::_Stream (1136) 00:04:20:10:12:97: got song from params, song index 0 [22-03-22 19:18:53.2882] Slim::Player::StreamingController::_Stream (1210) Song queue is now 0 [22-03-22 19:18:53.2888] Slim::Player::StreamingController::_Stream (1213) 00:04:20:10:12:97: preparing to stream song index 0 [22-03-22 19:18:53.2893] Slim::Player::Song::open (362) http://wumb.streamguys1.com/wumb919fast [22-03-22 19:18:53.2928] Slim::Player::TranscodingHelper::getConvertCommand2 (490) Error: Didn't find any command matches for type: mp3 [22-03-22 19:18:53.2934] Slim::Player::Song::open (386) seek=false time=0 canSeek=0SEEK_ERROR_MP3_UNKNOWN_DURATION [22-03-22 19:18:53.2946] Slim::Player::TranscodingHelper::getConvertCommand2 (493) Matched: mp3->mp3 via: - [22-03-22 19:18:53.2951] Slim::Player::Song::open (416) Transcoder: streamMode=I, streamformat=mp3 [22-03-22 19:18:53.2955] Slim::Player::Song::open (462) URL supports direct streaming [http://wumb.streamguys1.com/wumb919fast->http://wumb.streamguys1.com/wumb919fast] [22-03-22 19:18:53.2981] Slim::Player::StreamingController::_Stream (1282) 00:04:20:10:12:97: stream [22-03-22 19:18:53.2987] Slim::Player::Transporter::setDigitalInput (188) Switching to digital input 0 [22-03-22 19:18:53.3036] Slim::Player::StreamingController::_Stream (1319) Song queue is now 0 [22-03-22 19:18:53.3039] Slim::Player::StreamingController::_setPlayingState (2377) new playing state BUFFERING [22-03-22 19:18:53.3042] Slim::Player::StreamingController::_setStreamingState (2386) new streaming state STREAMING [22-03-22 19:18:53.4267] Slim::Player::Player::_buffering (1144) Buffering... 0 / 245760 [22-03-22 19:18:53.7302] Slim::Player::Player::_buffering (1144) Buffering... 1255 / 245760 [22-03-22 19:18:54.0343] Slim::Player::Player::_buffering (1144) Buffering... 3344 / 245760 [22-03-22 19:18:54.3387] Slim::Player::Player::_buffering (1144) Buffering... 3344 / 245760 [22-03-22 19:18:54.6428] Slim::Player::Player::_buffering (1144) Buffering... 11279 / 245760 [22-03-22 19:18:54.7329] Slim::Player::TranscodingHelper::getConvertCommand2 (490) Error: Didn't find any command matches for type: mp3 [22-03-22 19:18:54.9473] Slim::Player::Player::_buffering (1144) Buffering... 64000 / 245760 [22-03-22 19:18:55.2519] Slim::Player::Player::_buffering (1144) Buffering... 87771 / 245760 [22-03-22 19:18:55.5560] Slim::Player::Player::_buffering (1144) Buffering... 91951 / 245760 [] buffering lines removed 22 19:19:04.4251] Slim::Player::Player::_buffering (1144) Buffering... 234057 / 245760 [22-03-22 19:19:04.7281] Slim::Player::Player::_buffering (1144) Buffering... 242870 / 245760 [22-03-22 19:19:04.7288] Slim::Player::Player::_buffering (1145) +output... 4984 / 5292000 [22-03-22 19:19:04.7482] Slim::Player::StreamingController::playerTrackStarted (2200) 00:04:20:10:12:97 [22-03-22 19:19:04.7490] Slim::Player::StreamingController::_setPlayingState (2377) new playing state PLAYING [22-03-22 19:19:04.7496] Slim::Player::StreamingController::_Playing (368) Song 0 has now started playing [22-03-22 19:19:04.7510] Slim::Player::StreamingController::_Playing (397)
