I am not sure what happened here but 04.32 was the last timestamp of a track on the Touch that stopped playing. I then started playing the Touch and the mpd player at 06.48 and the Touch stopped at 07.49 while the mpd player continued. I started the Touch an mpd player again at 09.06 then started squeezeplay at 10.44. They all continued to play until 13.50 when they all stopped but the Touch screen stayed on.
At around 14.15 I finally realised that all the players had stopped and also realised that LMS, although still active had lost contact with the players and controllers, Then I restarted LMS.
Here is the server log from that period. It looks like Delicious Agony went offline at 04.31 when the Touch stopped so that probably explains why it stopped at a time which was not a Stream ID. I don't know what happened at 07.49 when the Touch stopped or what was going on at 10.48 when the log shows issues but playback seems to continue. LMS crashing remains a mystery and the log contains nothing until I restart LMS.
Code:[22-06-28 04:31:03.9817] Slim::Player::Protocols::HTTP::__ANON__ (497) cannot open session for http://deliciousagony.streamguys1.com/ 404 Not Available [22-06-28 04:31:04.2306] Slim::Player::Protocols::HTTP::__ANON__ (497) cannot open session for http://deliciousagony.streamguys1.com/ 404 Not Available [22-06-28 04:31:04.8854] Slim::Player::Protocols::HTTP::new (56) Couldn't create socket binding to - [22-06-28 04:31:04.8862] Slim::Player::Song::open (499) Warning: stream failed to open [http://deliciousagony.streamguys1.com/]. [22-06-28 04:31:09.3285] Slim::Player::Protocols::HTTP::new (56) Couldn't create socket binding to - [22-06-28 04:31:09.3293] Slim::Player::Song::open (499) Warning: stream failed to open [http://deliciousagony.streamguys1.com/]. [22-06-28 04:31:19.5268] Slim::Player::Protocols::HTTP::new (56) Couldn't create socket binding to - [22-06-28 04:31:19.5276] Slim::Player::Song::open (499) Warning: stream failed to open [http://deliciousagony.streamguys1.com/]. [22-06-28 04:31:34.3057] Slim::Player::Protocols::HTTP::new (56) Couldn't create socket binding to - [22-06-28 04:31:34.3065] Slim::Player::Song::open (499) Warning: stream failed to open [http://deliciousagony.streamguys1.com/]. [22-06-28 08:24:42.4846] Slim::Networking::Repositories::__ANON__ (147) Failed to fetch https://sourceforge.net/projects/lms-plugins-philippe44/files/dev/repo-sf.xml: Connect timed out: Resource temporarily unavailable [22-06-28 10:47:59.3919] Slim::Player::Protocols::HTTP::__ANON__ (497) cannot open session for http://deliciousagony.streamguys1.com/ 404 Not Available [22-06-28 10:47:59.4235] Slim::Player::Protocols::HTTP::__ANON__ (497) cannot open session for http://deliciousagony.streamguys1.com/ 404 Not Available [22-06-28 10:47:59.4327] Slim::Player::Protocols::HTTP::__ANON__ (497) cannot open session for http://deliciousagony.streamguys1.com/ 404 Not Available [22-06-28 10:47:59.7961] Slim::Player::Protocols::HTTP::__ANON__ (497) cannot open session for http://deliciousagony.streamguys1.com/ 404 Not Available [22-06-28 10:47:59.8042] Slim::Player::Protocols::HTTP::__ANON__ (497) cannot open session for http://deliciousagony.streamguys1.com/ 404 Not Available [22-06-28 10:47:59.8310] Slim::Player::Protocols::HTTP::__ANON__ (497) cannot open session for http://deliciousagony.streamguys1.com/ 404 Not Available [22-06-28 10:48:00.3957] Slim::Player::Protocols::HTTP::new (56) Couldn't create socket binding to - [22-06-28 10:48:00.3965] Slim::Player::Song::open (499) Warning: stream failed to open [http://deliciousagony.streamguys1.com/]. [22-06-28 10:48:02.8752] Slim::Player::Protocols::HTTP::new (56) Couldn't create socket binding to - [22-06-28 10:48:02.8760] Slim::Player::Song::open (499) Warning: stream failed to open [http://deliciousagony.streamguys1.com/]. [22-06-28 10:48:05.2351] Slim::Player::Protocols::HTTP::new (56) Couldn't create socket binding to - [22-06-28 10:48:05.2359] Slim::Player::Song::open (499) Warning: stream failed to open [http://deliciousagony.streamguys1.com/]. [22-06-28 10:48:07.3681] Slim::Player::Protocols::HTTP::new (56) Couldn't create socket binding to - [22-06-28 10:48:07.3689] Slim::Player::Song::open (499) Warning: stream failed to open [http://deliciousagony.streamguys1.com/]. [22-06-28 10:48:09.2939] Slim::Player::Protocols::HTTP::new (56) Couldn't create socket binding to - [22-06-28 10:48:09.2947] Slim::Player::Song::open (499) Warning: stream failed to open [http://deliciousagony.streamguys1.com/]. [22-06-28 10:48:14.3454] Slim::Player::Protocols::HTTP::new (56) Couldn't create socket binding to - [22-06-28 10:48:14.3462] Slim::Player::Song::open (499) Warning: stream failed to open [http://deliciousagony.streamguys1.com/]. [22-06-28 10:48:15.2368] Slim::Player::Protocols::HTTP::new (56) Couldn't create socket binding to - [22-06-28 10:48:15.2376] Slim::Player::Song::open (499) Warning: stream failed to open [http://deliciousagony.streamguys1.com/]. [22-06-28 10:48:17.3426] Slim::Player::Protocols::HTTP::new (56) Couldn't create socket binding to - [22-06-28 10:48:17.3436] Slim::Player::Song::open (499) Warning: stream failed to open [http://deliciousagony.streamguys1.com/]. [22-06-28 10:48:24.2293] Slim::Player::Protocols::HTTP::new (56) Couldn't create socket binding to - [22-06-28 10:48:24.2302] Slim::Player::Song::open (499) Warning: stream failed to open [http://deliciousagony.streamguys1.com/]. [22-06-28 10:48:30.2486] Slim::Player::Protocols::HTTP::new (56) Couldn't create socket binding to - [22-06-28 10:48:30.2494] Slim::Player::Song::open (499) Warning: stream failed to open [http://deliciousagony.streamguys1.com/]. [22-06-28 10:48:32.2073] Slim::Player::Protocols::HTTP::new (56) Couldn't create socket binding to - [22-06-28 10:48:32.2081] Slim::Player::Song::open (499) Warning: stream failed to open [http://deliciousagony.streamguys1.com/]. [22-06-28 10:48:39.2068] Slim::Player::Protocols::HTTP::new (56) Couldn't create socket binding to - [22-06-28 10:48:39.2076] Slim::Player::Song::open (499) Warning: stream failed to open [http://deliciousagony.streamguys1.com/].
Results 111 to 120 of 137
Thread: Radio station stops playing
-
2022-06-28, 06:53 #111
- Join Date
- Jan 2010
- Location
- Hertfordshire
- Posts
- 9,279
-
2022-06-28, 08:20 #112
- Join Date
- Oct 2005
- Location
- Ireland
- Posts
- 21,779
How long had the stream been running when it stopped at 4.32 ? Some services "reset" connections that to have been playing for "too long".
That said, the 404 error seems to indicate that the whole service went offline for a while.
DNS works but binding error usually means there is no TCP service on port 80 on the ip address - so it looks like a system crash but the streamguys status page shows no issues.
-
2022-06-28, 08:29 #113
- Join Date
- Jan 2010
- Location
- Hertfordshire
- Posts
- 9,279
Around 6 hours nothing excessive, the website had been down just before I started playing. When I mentioned it on Facebook Messenger they told me the site was down and to play the stream from TuneIn. I explained I was in the UK so that wasn't going to work. Around 5 or minutes later I got another message saying the site was up again. I wonder if the site went down again at 4.32.
Sent from my Pixel 3a using Tapatalk
-
2022-06-28, 10:02 #114
- Join Date
- Jan 2010
- Location
- Hertfordshire
- Posts
- 9,279
-
2022-06-28, 15:01 #115
- Join Date
- Jan 2010
- Location
- Hertfordshire
- Posts
- 9,279
I started playing on Squeezeplay at 3pm and playback stopped at around 10.35pm. I selected debug logging for audio.codec and audio.output and this is the complete log from squeezeplay with no entries after 3pm.
Code:1656409264.672 DEBUG audio.output - decode_portaudio_init:651 Portaudio version v19.1246976 1656409264.672 INFO audio.output - get_padevice_id:556 Using device 3. Primary Sound Driver (Windows DirectSound) 1656409264.672 INFO audio.output - decode_portaudio_init:682 Using latency 0.240000 1656409264.840 INFO audio.output - get_padevice_maxrate:630 Setting maximum samplerate to 192000 1656409264.840 DEBUG audio.output - decode_portaudio_openstream:403 Using sample rate 44100 1656409264.840 DEBUG audio.output - decode_portaudio_openstream:406 Using latency 0.240000 1656409264.876 DEBUG audio.output - decode_portaudio_openstream:445 Stream latency 0.240000 1656409264.876 DEBUG audio.output - decode_portaudio_openstream:446 Stream samplerate 44100.000000 1656409267.855 DEBUG audio.output - callback:118 pa status 4 1656409267.855 DEBUG audio.output - callback:118 pa status 4 1656409267.855 DEBUG audio.output - callback:118 pa status 4 1656409267.855 DEBUG audio.output - callback:118 pa status 4 1656409267.855 DEBUG audio.output - callback:118 pa status 4 1656409267.855 DEBUG audio.output - callback:118 pa status 4 1656409267.855 DEBUG audio.output - callback:118 pa status 4 1656409267.855 DEBUG audio.output - callback:118 pa status 4 1656409267.855 DEBUG audio.output - callback:118 pa status 4 1656409267.855 DEBUG audio.output - callback:118 pa status 4 1656409267.856 DEBUG audio.output - callback:118 pa status 4 1656409267.856 DEBUG audio.output - callback:118 pa status 4 1656409267.856 DEBUG audio.output - callback:118 pa status 4 1656409464.255 DEBUG audio.output - decode_portaudio_stop:365 decode_portaudio_stop 1656409465.246 DEBUG audio.codec - decode_mad_start:520 decode_mad_start() 1656409465.246 DEBUG audio.output - decode_portaudio_start:347 decode_portaudio_start 1656409465.335 DEBUG audio.codec - xing_parse:79 no xing header 1656409465.335 DEBUG audio.codec - decode_mad_output:413 Skip encoder_delay=529 pcm->length=1152 offset=529 1656409665.372 DEBUG audio.codec - decode_mad_stop:548 decode_mad_stop() 1656409665.372 DEBUG audio.output - decode_portaudio_stop:365 decode_portaudio_stop 1656409665.992 DEBUG audio.codec - decode_mad_start:520 decode_mad_start() 1656409665.992 DEBUG audio.output - decode_portaudio_start:347 decode_portaudio_start 1656409667.660 DEBUG audio.codec - xing_parse:79 no xing header 1656409667.661 DEBUG audio.codec - decode_mad_output:413 Skip encoder_delay=529 pcm->length=1152 offset=529 1656409681.373 DEBUG audio.codec - decode_mad_output:481 Reached end of stream 1656409681.398 DEBUG audio.codec - decode_mad_stop:548 decode_mad_stop() 1656409741.711 DEBUG audio.codec - decode_mad_start:520 decode_mad_start() 1656409741.711 DEBUG audio.output - decode_portaudio_start:347 decode_portaudio_start 1656409741.785 DEBUG audio.codec - xing_parse:84 xing magic 496e666f 1656409741.785 DEBUG audio.codec - xing_parse:99 xing frames: 15424 1656409741.785 DEBUG audio.codec - xing_parse:137 lame magic 4c414d45 bitlen 2016 1656409741.785 DEBUG audio.codec - xing_parse:162 encoder delay=1105 padding=923 1656409741.785 DEBUG audio.codec - xing_parse:163 total LAME samples 17768448 1656409741.785 DEBUG audio.codec - decode_mad_output:413 Skip encoder_delay=1105 pcm->length=1152 offset=1105 1656410134.783 DEBUG audio.codec - decode_mad_output:430 Removing encoder padding, lame_samples_remain=229 1656410134.783 DEBUG audio.codec - decode_mad_output:430 Removing encoder padding, lame_samples_remain=0 1656410134.783 DEBUG audio.codec - decode_mad_output:430 Removing encoder padding, lame_samples_remain=0 1656410134.783 DEBUG audio.codec - decode_mad_output:439 Decoded more samples (17770752) than expected (0), assuming invalid LAME header and ignoring padding 1656422206.503 DEBUG audio.codec - decode_mad_output:481 Reached end of stream 1656422206.537 DEBUG audio.codec - decode_mad_stop:548 decode_mad_stop() 1656422206.538 DEBUG audio.output - decode_portaudio_stop:365 decode_portaudio_stop 1656424850.203 DEBUG audio.output - decode_portaudio_stop:365 decode_p
-
2022-06-29, 00:39 #116
- Join Date
- Oct 2005
- Location
- Ireland
- Posts
- 21,779
-
2022-06-29, 00:47 #117
- Join Date
- Oct 2005
- Location
- Ireland
- Posts
- 21,779
I've been using Squeezeplay on Linux which AFAICT doesn't use PortAudio (I.e. it looks like ALSA) so I'm not sure if underrun or other error messages are directly comparable.
It looks itis reporting that some data was "lost" and so MP3 frames are are undecodeable but perhaps this is due to Portaudio handling errors differently
-
2022-06-29, 02:12 #118
- Join Date
- Jan 2010
- Location
- Hertfordshire
- Posts
- 9,279
-
2022-06-29, 07:19 #119
- Join Date
- Oct 2005
- Location
- Ireland
- Posts
- 21,779
I have a small dumb program which just reads the stream in icy-metaint size chunks (i.e about 16000 bytes), looks for metadata and chops the remaining audio into files whenever it sees metadata.
Chunks normally arrive about 1 per sec (16000*8 = 128000bits so 128kbits/sec) but some take longer - the stream is lumpy.
The stream is read with blocking reads (i.e. it waits for complete 16000 bytes or full metdata string) - very occasionally, maybe once per long session - it just hangs, program waits for the chunk but no more data. I'm sure if I did a "non-blocking" read with proper error management, I could get an error code.
Summary, I think it is still a streaming problem with this station and it will stop every so often
-
2022-06-29, 11:53 #120
- Join Date
- Jan 2010
- Location
- Hertfordshire
- Posts
- 9,279
Here is a squeezeplay log where playback stopped. Does it mean anything?
Code:1656528254.316 DEBUG audio.decode - :451 31.7%/99.8% 1656528255.444 DEBUG audio.decode - :451 31.6%/100.0% 1656528256.525 DEBUG audio.decode - :451 31.6%/100.0% 1656528257.765 DEBUG audio.decode - :451 31.4%/99.4% 1656528258.812 DEBUG audio.decode - :451 31.8%/99.8% 1656528259.892 DEBUG audio.decode - :451 31.7%/99.3% 1656528261.016 DEBUG audio.decode - :451 31.6%/99.8% 1656528262.096 DEBUG audio.decode - :451 31.6%/99.9% 1656528263.176 DEBUG audio.decode - :451 31.8%/99.4% 1656528264.211 DEBUG audio.decode - :451 31.6%/99.4% 1656528265.292 DEBUG audio.decode - :451 31.7%/99.2% 1656528266.416 DEBUG audio.decode - :451 31.7%/99.9% 1656528267.496 DEBUG audio.decode - :451 31.7%/99.8% 1656528268.503 DEBUG audio.decode - :451 31.6%/100.0% 1656528269.571 DEBUG audio.decode - :451 31.7%/99.8% 1656528270.606 DEBUG audio.decode - :451 31.6%/99.9% 1656528271.747 DEBUG audio.decode - :451 31.4%/99.9% 1656528272.650 DEBUG audio.decode - :858 strm q 1656528272.650 DEBUG audio.decode - :1265 stopping local pause timer 1656528272.650 DEBUG audio.decode - decode_stop:664 decode_stop 1656528272.650 DEBUG audio.decode - :194 source=off 1656528272.650 DEBUG audio.decode - :754 disconnect streambuf 1656528272.650 DEBUG audio.decode - decode_stop_handler:190 decode_stop_handler 1656528272.650 DEBUG audio.codec - decode_mad_stop:548 decode_mad_stop() 1656528273.219 DEBUG audio.decode - :1265 stopping local pause timer 1656528273.219 DEBUG audio.decode - :1195 gainL, gainR: 15