PDA

View Full Version : Radio "freezes" periodically



Eisbaer2
2017-12-19, 07:21
Hello,
for about 6 years I have a squeezebox radio in use (with current firmware 7.7.3 r16676),
mainly to listen to different radio stations. It is physically connected via WIFI and almost always conntected to mysqueezebox.com (very rarely to the
local LMS).

Actually, it should be like that (normal state, if it works):
1) I turn on the radio by pressing one of the favorites button on the internet radio station.
2) The logo & the information of the web radio is displayed.
3) The message "Connection is established" (something like that, my SBR is in German language) appears
4) After a few seconds the web radio is playing.

For several months now I unfortunately have the problem that every 1-2 days the SBR does the following instead:
I) Turn on the radio by pressing the favorites button on the internet radio station.
II) The logo of the last played radio station appears. More does not happen. No attempt of establishing a connection, no sound.
III) If I switch to another station, nothing changes in the display. Only going to the menu
and navigating there works.
IV) The repeated manual selection of my own WIFI in the menu fails (WIFI icon
then changes from white to red).

Amazingly it is possible to connect to the radio in this faulty state via tablet with the
Squeezebox app and start any station from there. That reactivates the
Possibility of a direct selection of web radio stations on the SBR itself unfortunately not.

The problem can be fixed temporarily by a complete shutdown and restart of the radio. Only I don't want to do that every day...

Things I alread tried (without success):

- Going back to an older firmware
- reparing my network via menu
- factory reset

Somebody has an idea what else I can try to fix the problem?

Here is a sample log file:
24222

Best regards
Eisbaer2

reinholdk
2017-12-19, 13:05
Is this a current log file? The messages are from March. You don't have a network issue?

Eisbaer2
2017-12-19, 14:25
Is this a current log file? The messages are from March. You don't have a network issue?

The issue started before March. I don't think I have a network issue. All other wifi-connected devices has no problems and I can "see" the SBR during the freeze in the Squeezebox app.

DJanGo
2017-12-20, 01:22
Hi,

that looks like a "routing / dns" issue...

Your able to see the radio in your own network
the radio cant connect to the internet (mysqueezebox.com)

Ive had a similar issue [i am not using any outside streams like mysb] with my ISP until i setup my own dns service in my local network.

Try to give your radio a static ip with eg 8.8.8.8 as dns server....

edit The messages are from March.
are you sure your radio is up2date (timeserver) ?

alfista
2017-12-20, 02:51
Hi,

that looks like a "routing / dns" issue...

Your able to see the radio in your own network
the radio cant connect to the internet (mysqueezebox.com)

I'm not so sure. Since it is possible to control the Radio via the app it seems like it must be connected to mysqueezebox unless the Radio on its own accord has connected to LMS.

bpa
2017-12-20, 03:23
Does the router have wifi power saving ?

edit:
Does the radio have a static IP address ?

Eisbaer2
2017-12-20, 06:45
Does the router have wifi power saving ?
edit:
Does the radio have a static IP address ?

1) I think my router has wifi power saving enabled. Will disable it but I don't think it'll solve the problem cause the faulty state also occurs when a lot of other wifi devices are connected.

2) My SBR has no static IP address. Do you really mean that (like mentioned here: http://forums.slimdevices.com/showthread.php?72803-Static-IP-on-Radio/page3) or do you mean IP reservation in the router DHCP configuration?

Best regards, Eisbaer2

Eisbaer2
2017-12-20, 06:49
Hi,
Try to give your radio a static ip with eg 8.8.8.8 as dns server....

How to do that? Like mentioned here: http://forums.slimdevices.com/showthread.php?72803-Static-IP-on-Radio/page3 ?


The messages are from March. [/b]
are you sure your radio is up2date (timeserver) ?

It is up to date. The problem consists for about a year now. In march I tried to solve the problem with a German forum and downloaded the log file then. I have no newer so far but the problem also didn't change.

Thanks and best regards! Eisbaer2

DJanGo
2017-12-20, 06:58
I'm not so sure. Since it is possible to control the Radio via the app it seems like it must be connected to mysqueezebox unless the Radio on its own accord has connected to LMS.
i am also not sure - i didnt use any streams...

whenever that happend again - please poweroff your radio.
Is your radio still listed in mysbq?

I dont know - whats needed for mysbq that it may think your radio is still on. Maybe (really dont know that) its just "attached" to mysbq.

Eisbaer2
2017-12-20, 09:13
Is your radio still listed in mysbq?

Do you mean mysbc? If yes: I'll test it ASAP and write it here.

Best regards, Eisbaer2

Eisbaer2
2017-12-20, 15:17
Do you mean mysbc? If yes: I'll test it ASAP and write it here.

Best regards, Eisbaer2

Ok, very strange. My radio was/is in faulty state again: When I turn it on (from standby) it shows the information of the last station that was turned on. It only doesn't play any music and it isn't possible to change to another station. And the wifi icon was red.

So I logged in in mysqc and changed the station from there. And - surprisingly - it worked! I hear the sound from the chosen web radio station. And the wifi icon turned to white. But: the faulty state continues. It isn't possible to change to another station with the buttons of the SBR it fails (nothing happens). When trying it via the menu (as mentioned the menu works) the turning blue cycle appears and stays there forever or until cancelling with the back button.

So full funtional via mysbc, almost non-functional via the on site hardware.

I'm at a loss... Ideas?

Eisbaer2
2017-12-20, 15:22
Does the router have wifi power saving ?

Update: No, it hasn't.


Does the radio have a static IP address ?

It has DHCP IP reservation. Do you think a static IP could solve my problem even though my SBR can be controlled remotely?

Best regards, Eisbaer2

mherger
2017-12-21, 00:58
Please connect the Radio to your LMS for a while. Would it show the same symptoms?

Are you using multiple add-ons like the weather forecast? If so, get rid of them all.

And please get us a new log file. We know this is old, and that you believe it behaves the same. But still.

bpa
2017-12-21, 02:18
It has DHCP IP reservation. Do you think a static IP could solve my problem even though my SBR can be controlled remotely?

The questions deals with two possibiltiies.
1. If using dynamic IP then could there be issues about chaging IP address (e.g. old IP cached somewhere)
2. If not using DHCP, could there be an error in basic network settings.

Using a reserved IP address with DHCP means:
* that problems due to a changing IP address can be discounted ;
* also by using DHCP means an error due to settings can also probably be ruled out.

Eisbaer2
2018-01-10, 05:19
I'm sorry for replying so late. I tried a few things:
- DHCP-IP-reservation
- Deleting the SBR in my router and creating a new DHCP-IP-reservation
- static IP

So far no change. My SBR still freezes after about 1-2 days after the last reboot.

Attached several current log files.

Any further ideas?

bpa
2018-01-10, 05:26
I'm sorry for replying so late. I tried a few things:
- DHCP-IP-reservation
- Deleting the SBR in my router and creating a new DHCP-IP-reservation
- static IP

So far no change. My SBR still freezes after about 1-2 days after the last reboot.

Attached several current log files.

Any further ideas?

The logs can be helpful but only if context is clear - they may be clear to you but not to someone who last looked at this issue 3 weeks ago.
How do the logs relate to each other ?

Are these a random snapshot of the log or are they a log of when the SBR froze ? If it froze at what time did it freeze ?

Eisbaer2
2018-01-10, 05:35
The logs can be helpful but only if context is clear - they may be clear to you but not to someone who last looked at this issue 3 weeks ago.
How do the logs relate to each other ?

Are these a random snapshot of the log or are they a log of when the SBR froze ? If it froze at what time did it freeze ?

Unfortunately I don't know exactly when the SBR freezes. Most of the time I want to start the SBR in the morning and have to realize the SBR froze someone during the night.

The three log files are from yesterday:
1) messages.0_cut.txt is the oldest one
2) messages.txt is newer
3) Then I changed the SBR to a static IP and rebooted. So messages_static_ip.txt is the newest one with no freezes during the short time of logging.

How can I help clarifying the context even more?

bpa
2018-01-10, 06:19
Unfortunately I don't know exactly when the SBR freezes. Most of the time I want to start the SBR in the morning and have to realize the SBR froze someone during the night.

The three log files are from yesterday:
1) messages.0_cut.txt is the oldest one
2) messages.txt is newer
3) Then I changed the SBR to a static IP and rebooted. So messages_static_ip.txt is the newest one with no freezes during the short time of logging.

The logs vary from 15mins to 40 mins all ending about 22:00 at night. So they are unlikely to show the "freeze" event.

You need to get an all night log where the Radio goes from Working to frozen at some point in the log. The usual way is to ssh from a PC into the Radio from a Terminal/putty type application and then issue a "tail -f" command on the log file -- ensure the Terminal/Putty command has an "infinite" scrolling window. Then leave ssh run until Radio has frozen (remember to disable power saving on PC). When Radio is known to have frozen copy logged message in the scrolling window into a file on the PC - Zip and attach to a post.

Eisbaer2
2018-01-10, 06:51
The logs vary from 15mins to 40 mins all ending about 22:00 at night. So they are unlikely to show the "freeze" event.

You need to get an all night log where the Radio goes from Working to frozen at some point in the log. The usual way is to ssh from a PC into the Radio from a Terminal/putty type application and then issue a "tail -f" command on the log file -- ensure the Terminal/Putty command has an "infinite" scrolling window. Then leave ssh run until Radio has frozen (remember to disable power saving on PC). When Radio is known to have frozen copy logged message in the scrolling window into a file on the PC - Zip and attach to a post.

Thanks. So far I only copied the files via SCP from the SBR to my PC. Will try your suggestion.

bpa
2018-01-10, 06:55
Thanks. So far I only copied the files via SCP from the SBR to my PC. Will try your suggestion.

I'm not sure if the log file in the SBR has a size limit since it is kept in RAM. Also if the "freeze" results in the Radio rebooting - the SBR log file is cleared and message will be lost - using the "tail -f" mehtod - if the radio reboots the SSH will be broken but the message will be "kept" in the scrolling window.

Eisbaer2
2018-01-10, 06:58
I'm not sure if the log file in the SBR has a size limit since it is kept in RAM. Also if the "freeze" results in the Radio rebooting - the SBR log file is cleared and message will be lost - using the "tail -f" mehtod - if the radio reboots the SSH will be broken but the message will be "kept" in the scrolling window.

There is no reboot after a freeze. I would be glad if there was one - a reboot heals the faulty state temporarily. No. A freeze remains until I restart my SBR manually.

bpa
2018-01-10, 07:12
There is no reboot after a freeze. I would be glad if there was one - a reboot heals the faulty state temporarily. No. A freeze remains until I restart my SBR manually.

I presume you can ssh into SBR when it is "frozen" since you use scp to copy log files when it is frozen ?

IIRC the SBR h/w has a watchdog timer which has to be reset regularly - if not then SBR will reboot. Since watch dog is not expiring and ssh/scp works - it may mean some processes are stuck. It may be a good idea to do a "ps" when SBR is OK and another "ps" when SBR is frozen - to compare process tree.

Eisbaer2
2018-01-10, 22:12
I presume you can ssh into SBR when it is "frozen" since you use scp to copy log files when it is frozen ?

IIRC the SBR h/w has a watchdog timer which has to be reset regularly - if not then SBR will reboot. Since watch dog is not expiring and ssh/scp works - it may mean some processes are stuck. It may be a good idea to do a "ps" when SBR is OK and another "ps" when SBR is frozen - to compare process tree.

SBR freezed last night as usual. "ps" before and after freeze is identical.
But I logged all night :-) Log file is attached.

Update: I just noticed there is a "gap" in the log file (nothing between 23:04 and 5:52). So I don't know if the log file can help. Don't know why that happened. Energy saving was disabled - my laptop ran all night. Will try again next night.

bpa
2018-01-11, 02:22
The freeze problem is odd so at the moment you have to look around to find any signs and consider anything that is not "normal".

When I asked to compare process tree in "ps" - I had hoped you would compare CPU and memory usage of each process to see if any process has started to behave oddly.

In the log why was it necessary to issue "tail -f" commands a few times ?

Before each time the "tail -f"and before the "gap" in the log the request timeout messages appear


Jan 10 23:03:37 squeezeplay: WARN net.thread - NetworkThread.lua:146 network thread timeout for Task(SocketHttp {baby.squeezenetwork.com}(R))
Jan 10 23:04:22 squeezeplay: WARN net.thread - NetworkThread.lua:146 network thread timeout for Task(SocketHttp {mysqueezebox.com_Request}(R))


This would indicate there are network problems in addition or possibly presaging the freeze - since ssh is over the network it may also explain gap.


edit:

Also after 5:55 the following error occurs frequently - again network related.


ERROR net.http - SocketHttp.lua:390 SocketHttp {Wolfgangs MP3s_Chunked}:t_sendRequest.pump: No route to host


There seems to be an alarms activated but radio cannot connect to the Server "Wolfgangs MP3s" to play the alarm. At a guess the overnight freeze is somehow related to this. Do you have any alarms set ?

Eisbaer2
2018-01-11, 02:59
Also after 5:55 the following error occurs frequently - again network related.


ERROR net.http - SocketHttp.lua:390 SocketHttp {Wolfgangs MP3s_Chunked}:t_sendRequest.pump: No route to host


There seems to be an alarms activated but radio cannot connect to the Server "Wolfgangs MP3s" to play the alarm. At a guess the overnight freeze is somehow related to this. Do you have any alarms set ?

No, I have never used alarms. To be sure I just checked via mysqueezebox.com => there is no alarm set/active.
(again, my SBR is in the "local" freeze state but I can see and control it via MSC).

bpa
2018-01-11, 03:35
No, I have never used alarms. To be sure I just checked via mysqueezebox.com => there is no alarm set/active.
(again, my SBR is in the "local" freeze state but I can see and control it via MSC).

What is MSC ?

What is "Wolfgangs MP3s" ?
If it is a LMS server - then check for alarms on it ?

bpa
2018-01-11, 03:45
What is happening at 5:52 ?

Did you press Power on Button ? Followed by Power off ? Could it be an alarm even an old "deleted" one ?

What is the stream "/swr/swr3/live/mp3/128/stream.mp3?ar-distributor=f0a1 "
Is it a Favorite ?
Is it set up on any alarm ?




Jan 10 23:03:37 squeezeplay: WARN net.thread - NetworkThread.lua:146 network thread timeout for Task(SocketHttp {baby.squeezenetwork.com}(R))
Jan 10 23:04:22 squeezeplay: WARN net.thread - NetworkThread.lua:146 network thread timeout for Task(SocketHttp {mysqueezebox.com_Request}(R))
Jan 11 05:52:18 squeezeplay: INFO squeezeplay - JiveMain.lua:207 Turn soft power on
Jan 11 05:52:18 squeezeplay: WARN squeezebox.server - SlimServer.lua:679 wakeOnLan(): SKIPPING WOL, self.mac: nil, self:isSqueezeNetwork(): true
Jan 11 05:52:18 squeezeplay: INFO applet.SlimMenus - SlimMenusApplet.lua:502 _menuSink(1) nil menuDirective: add isCurrentServer:true
Jan 11 05:52:18 squeezeplay: INFO applet.SlimMenus - SlimMenusApplet.lua:802 hiding any 'connecting to server' popup after menu response from current server, SlimServer {mysqueezebox.com}
Jan 11 05:52:18 squeezeplay: INFO applet.ChooseMusicSource - ChooseMusicSourceApplet.lua:543 Hiding popup, exists?: nil
Jan 11 05:52:19 squeezeplay: INFO applet.SlimDiscovery - SlimDiscoveryApplet.lua:517 notify_playerPower: true
Jan 11 05:52:19 squeezeplay: WARN applet.AlarmSnooze - AlarmSnoozeApplet.lua:323 notify_playerModeChange: - audioState is 0
Jan 11 05:52:19 squeezeplay: INFO applet.NowPlaying - NowPlayingApplet.lua:422 enable volume UI in NP
Jan 11 05:52:20 squeezeplay: INFO audio.decode - decode_start_handler:279 init decoder mp3
Jan 11 05:52:20 squeezeplay: INFO audio.decode - Playback.lua:476 connect 212.122.133.12:80 GET /swr/swr1/bw/mp3/128/stream.mp3?ar-distributor=f0a1 HTTP/1.0^M
Jan 11 05:52:20 squeezeplay: INFO audio.decode - Playback.lua:479 GET /swr/swr1/bw/mp3/128/stream.mp3?ar-distributor=f0a1 HTTP/1.0^M
Jan 11 05:52:20 squeezeplay: Accept: */*^M
Jan 11 05:52:20 squeezeplay: Cache-Control: no-cache^M
Jan 11 05:52:20 squeezeplay: User-Agent: iTunes/4.7.1 (Unix; N; linux; x86_64-linux; EN; utf8) SqueezeNetwork/7.7.6-sn/TRUNK^M
Jan 11 05:52:20 squeezeplay: Icy-MetaData: 1^M
Jan 11 05:52:20 squeezeplay: Connection: close^M
Jan 11 05:52:20 squeezeplay: Host: swr-swr1-bw.cast.addradio.de^M
Jan 11 05:52:20 squeezeplay: ^M
Jan 11 05:52:21 squeezeplay: INFO applet.NowPlaying - NowPlayingApplet.lua:422 enable volume UI in NP
Jan 11 05:52:24 squeezeplay: INFO squeezeplay.applets - AppletManager.lua:708 store settings: Playback
Jan 11 05:52:24 squeezeplay: INFO audio.decode - decode_start_handler:279 init decoder mp3
Jan 11 05:52:24 squeezeplay: INFO audio.decode - Playback.lua:476 connect 212.122.133.12:80 GET /swr/swr3/live/mp3/128/stream.mp3?ar-distributor=f0a1 HTTP/1.0^M
Jan 11 05:52:24 squeezeplay: INFO audio.decode - Playback.lua:479 GET /swr/swr3/live/mp3/128/stream.mp3?ar-distributor=f0a1 HTTP/1.0^M
Jan 11 05:52:24 squeezeplay: Accept: */*^M
Jan 11 05:52:24 squeezeplay: Cache-Control: no-cache^M
Jan 11 05:52:24 squeezeplay: User-Agent: iTunes/4.7.1 (Unix; N; linux; x86_64-linux; EN; utf8) SqueezeNetwork/7.7.6-sn/TRUNK^M
Jan 11 05:52:24 squeezeplay: Icy-MetaData: 1^M
Jan 11 05:52:24 squeezeplay: Connection: close^M
Jan 11 05:52:24 squeezeplay: Host: swr-swr3-live.cast.addradio.de^M
Jan 11 05:52:24 squeezeplay: ^M
Jan 11 05:52:25 squeezeplay: INFO applet.NowPlaying - NowPlayingApplet.lua:422 enable volume UI in NP
Jan 11 05:52:26 squeezeplay: INFO applet.NowPlaying - NowPlayingApplet.lua:422 enable volume UI in NP
Jan 11 05:52:28 squeezeplay: INFO squeezeplay - JiveMain.lua:200 Turn soft power off

Eisbaer2
2018-01-11, 04:12
What is MSC ?

What is "Wolfgangs MP3s" ?
If it is a LMS server - then check for alarms on it ?

Thanks for your help and your questions.

MSC = mysqueezebox.com

Yes, "Wolfgangs MP3s" is an LMS on my NAS (my NAS is usually only awake for about 6 hours from about 17:00 to 22:00).

At the moment I can't check alarms on the LMS - must do that from @home. I doubt that that could be the reason. For example yesterday my NAS with the LMS went offline at 22:05 and at 23:00 my SBR was still ok.

Eisbaer2
2018-01-11, 04:15
What is happening at 5:52 ?
Did you press Power on Button ? Followed by Power off ? Could it be an alarm even an old "deleted" one ?

Yes I pressed the Power on Button, Followed by Power off later.


What is the stream "/swr/swr3/live/mp3/128/stream.mp3?ar-distributor=f0a1 " Is it a Favorite ? Is it set up on any alarm ?

It is one of my Favorite Web Radios, yes. As mentioned no alarms are active on my SBR.

bpa
2018-01-11, 04:43
At the moment I can't check alarms on the LMS - must do that from @home. I doubt that that could be the reason. For example yesterday my NAS with the LMS went offline at 22:05 and at 23:00 my SBR was still ok.

IIRC the Alarm times within 24hrs are remembered in SB Boom, Touch and Radio in case connection to internet / server is lost. This means SBR will wake to an alarm even if not connected to a server/internet and play an internal backup music file if the requested audio is not available.

edit:

Also check Alarm using the SBR menus when connecrted to LMS and also when connected mysqueezebox.com in case of discrepancy.

bpa
2018-01-11, 04:49
Yes I pressed the Power on Button, Followed by Power off later.

You're not being forthcoming with information. I feel I have to drag this information from you. Logs only have meaning when context and activities are fully described.

You said SBR froze last night but you have not said when you discovered it was frozen, nor did you mention you did Power on and Power off.

When you did Power on - was it using Power button or with a preset button ?

When you did Power on - was Radio frozen or working correctly ? Did it play audio or did power off so quickly the SBR did not have a chance ?

Asked before but not answered - Why do you repeatedly do "tail -f" command - there should be only one at the start ?

Eisbaer2
2018-01-11, 05:44
You're not being forthcoming with information. I feel I have to drag this information from you. Logs only have meaning when context and activities are fully described.
You said SBR froze last night but you have not said when you discovered it was frozen, nor did you mention you did Power on and Power off.
When you did Power on - was it using Power button or with a preset button ?

I'm sorry. I thought the decription in my first post is enough. It is always exactly like mentioned there (and it was also like that this morning):

I) Turn on the radio by pressing the favorites button on the internet radio station. (it doesn't matter if it is the last used station or another one).
II) The logo of the last played radio station appears. More does not happen. No attempt of establishing a connection, no sound.
III) If I switch to another station, nothing changes in the display. Only going to the menu
and navigating there works.


When you did Power on - was Radio frozen or working correctly ? Did it play audio or did power off so quickly the SBR did not have a chance ?

I pressed a favorite button at about 5:52 and the radio was frozen like mentioned above (II).


Asked before but not answered - Why do you repeatedly do "tail -f" command - there should be only one at the start ?

Sorry, forgot to answer that. In the first minutes I wanted to copy some of the log file messages and made mistakes (I am no hardcore linux user ;-) and then putty showed no new information so I ended that via CTRL + C and started tail -f again. Had nothing to do with my strange SBR behaviour.

bpa
2018-01-11, 07:03
I'm sorry. I thought the decription in my first post is enough. It is always exactly like mentioned there (and it was also like that this morning):

I) Turn on the radio by pressing the favorites button on the internet radio station. (it doesn't matter if it is the last used station or another one).
II) The logo of the last played radio station appears. More does not happen. No attempt of establishing a connection, no sound.
III) If I switch to another station, nothing changes in the display. Only going to the menu
and navigating there works.
Thanks. Sorry for not fuilly reading the thread but I came to the thread a bit late but I have also learned it is best not to assume user actions.


I pressed a favorite button at about 5:52 and the radio was frozen like mentioned above (II).

Selected message from the Log - note the times


Jan 11 05:52:18 squeezeplay: INFO squeezeplay - JiveMain.lua:207 Turn soft power on
Jan 11 05:52:20 squeezeplay: INFO audio.decode - Playback.lua:479 GET /swr/swr1/bw/mp3/128/stream.mp3?ar-distributor=f0a1 HTTP/1.0^M
Jan 11 05:52:28 squeezeplay: INFO squeezeplay - JiveMain.lua:200 Turn soft power off
Jan 11 05:53:23 squeezeplay: WARN applet.SlimBrowser - SlimBrowserApplet.lua:3084 notify_networkOrServerNotOK()
Jan 11 05:53:23 squeezeplay: WARN applet.SlimBrowser - SlimBrowserApplet.lua:3089 this is a server error
Jan 11 05:53:23 squeezeplay: WARN applet.SlimMenus - SlimMenusApplet.lua:188 notify_networkOrServerNotOK
Jan 11 05:53:23 squeezeplay: INFO applet.AlarmSnooze - AlarmSnoozeApplet.lua:379 notify_serverDisconnected: SlimServer {mysqueezebox.com} is now disconnected
.
.
Jan 11 05:53:26 squeezeplay: INFO net.comet - Comet.lua:644 Comet {Wolfgangs MP3s}: _handshake error: No route to host
.
Jan 11 05:53:31 squeezeplay: ERROR net.http - SocketHttp.lua:390 SocketHttp {Wolfgangs MP3s_Chunked}:t_sendRequest.pump: No route to host
.
Jan 11 05:53:38 squeezeplay: ERROR net.http - SocketHttp.lua:390 SocketHttp {Wolfgangs MP3s_Chunked}:t_sendRequest.pump: No route to host
.
Jan 11 05:53:46 squeezeplay: ERROR net.http - SocketHttp.lua:390 SocketHttp {Wolfgangs MP3s_Chunked}:t_sendRequest.pump: No route to host


To help determine what other logging needs to be enabled - a guess has to be made at what is happening.

It looks like network routing (but not network interface) is down at 5:52:18. Attempt to play station is made at :5:52:20 would take maybe about 1 min to timeout but you hit Power Off at 5:52:28 (8 secs later) before timeout happen. Then one minute later at 5:53:23 SBR has determined connection to Server/mysqueezebox.com is not working - probably a timeout expired. After this a loop starts ("no route to host") which repeats every 5-8secs. I don't know SBR code well enough to know if this is right or not but it implies SBR is trying to recover.

I'll try to replicate the sequence on my SBR to see what should be in a "normal" log with / without mysqueezebox.com available.

Eisbaer2
2018-01-11, 13:44
IIRC the Alarm times within 24hrs are remembered in SB Boom, Touch and Radio in case connection to internet / server is lost. This means SBR will wake to an alarm even if not connected to a server/internet and play an internal backup music file if the requested audio is not available.
Also check Alarm using the SBR menus when connecrted to LMS and also when connected mysqueezebox.com in case of discrepancy.

Tested it all. No alarm was active/set.
I've disabled all plugins on the LMS. Maybe that will change anything.

bpa
2018-01-11, 14:01
Tested it all. No alarm was active/set.
I've disabled all plugins on the LMS. Maybe that will change anything.
The SBR was connected to mysqeezebox.com late at night and also when you press power on - so I can't see LMS plugins having any effect as SBR was not in contact with LMS in between.

Do you have any applets installed on SBR (i.e. from Applet installer menu such as Album Flow, Settings Remover, Custom clock etc.) ?

Eisbaer2
2018-01-11, 14:05
The SBR was connected to mysqeezebox.com late at night and also when you press power on - so I can't see LMS plugins having any effect as SBR was not in contact with LMS in between.

Do you have any applets installed on SBR (i.e. from Applet installer menu such as Album Flow, Settings Remover, Custom clock etc.) ?

Two are installed on SBR:
- "Radio.de"
- "Sound & Effekte"

Both are installed for more than six years. I just uninstalled both and watch...

bpa
2018-01-11, 14:56
Two are installed on SBR:
- "Radio.de"
- "Sound & Effekte"

Both are installed for more than six years. I just uninstalled both and watch...

They are "apps" not "applets". They were installed using the App Gallery not via the Settings/Advanced/Applet Installer

Apps do not install any code in the SBR. Applets install code in the SBR.

Eisbaer2
2018-01-12, 00:11
No freeze this morning :)

bpa
2018-01-12, 02:40
I tried to reproduce your log by disconnected internet link at modem so leaving local LAN/Wifi operational.
The log difference shows that when you wake up your SBR to play a stream - it has been disconnected from my your LMS servers (Wolfgangs_MP3s) and mysqueezebox.com. The error "no route to source" may be because NAS is asleep. SBT logs multiple errors trying to connected to LMS. SBR makes connection to mysqueezebox.com after about 1 mins after initial "Power on".

The "frozen" seems to be the result of some sort of network issue. I think SBR is "frozen" because it is waiting while trying to set up communication with mysqeezebox.com.

When you say SBR is frozen - how long did you wait before doing other tasks to get SBR "working" ?

When in a frozen state - if you wait more than 1 mins and then press Preset button again - does SBR work ?

The issues is to determine if the problem connecting to mysqueezebox.com is a network issue between router and ISP or a network issue inside SBR ?

Comparing similar logs message:
your log


Jan 11 05:53:26 squeezeplay: ERROR net.http - SocketHttp.lua:390 SocketHttp {Wolfgangs MP3s_Chunked}:t_sendRequest.pump: No route to host
Jan 11 05:53:26 squeezeplay: stack traceback:
Jan 11 05:53:26 squeezeplay: /usr/share/jive/jive/net/SocketHttp.lua:390: in function 'pump'
Jan 11 05:53:26 squeezeplay: /usr/share/jive/jive/net/SocketTcp.lua:200: in function 'writePump'
Jan 11 05:53:26 squeezeplay: /usr/share/jive/jive/net/Socket.lua:186: in function </usr/share/jive/jive/net/Socket.lua:184>
Jan 11 05:53:26 squeezeplay: INFO net.comet - Comet.lua:644 SlimServer {Wolfgangs MP3s} is now disconnected
Jan 11 05:53:26 squeezeplay: WARN applet.AlarmSnooze - AlarmSnoozeApplet.lua:392 notify_serverDisconnected: SlimServer {Wolfgangs MP3s} - disconnected, but no server alarm in progress : nil
Jan 11 05:53:26 squeezeplay: INFO net.comet - Comet.lua:1047 Comet {Wolfgangs MP3s}: advice is retry, connect in 2.06 seconds
Jan 11 05:53:27 squeezeplay: INFO squeezebox.server - SlimServer.lua:765 connected mysqueezebox.com
Jan 11 05:53:27 squeezeplay: INFO applet.AlarmSnooze - AlarmSnoozeApplet.lua:360 notify_serverConnected: SlimServer {mysqueezebox.com} is now connected


My log


Jan 12 01:45:39 squeezeplay: ERROR net.http - SocketHttp.lua:375 SocketHttp {mysqueezebox.com_Chunked}:t_sendRequest.pump: inactivity timeout
Jan 12 01:45:39 squeezeplay: stack traceback:
Jan 12 01:45:39 squeezeplay: /usr/share/jive/jive/net/SocketHttp.lua:375: in function 'pump'
Jan 12 01:45:39 squeezeplay: /usr/share/jive/jive/net/SocketTcp.lua:200: in function 'writePump'
Jan 12 01:45:39 squeezeplay: /usr/share/jive/jive/net/Socket.lua:186: in function </usr/share/jive/jive/net/Socket.lua:184>
Jan 12 01:45:39 squeezeplay: INFO net.comet - Comet.lua:810 Comet {mysqueezebox.com}: _getEventSink error: inactivity timeout
Jan 12 01:45:39 squeezeplay: INFO net.comet - Comet.lua:1006 Comet {mysqueezebox.com}: handleAdvice state=CONNECTING
Jan 12 01:45:39 squeezeplay: INFO squeezebox.server - SlimServer.lua:789 disconnected mysqueezebox.com idleTimeoutTriggered: nil
Jan 12 01:45:39 squeezeplay: INFO applet.AlarmSnooze - AlarmSnoozeApplet.lua:379 notify_serverDisconnected: SlimServer {mysqueezebox.com} is now disconnected
Jan 12 01:45:39 squeezeplay: WARN applet.AlarmSnooze - AlarmSnoozeApplet.lua:392 notify_serverDisconnected: SlimServer {mysqueezebox.com} - disconnected, but no server alarm in progress : nil
Jan 12 01:45:39 squeezeplay: INFO net.comet - Comet.lua:1047 Comet {mysqueezebox.com}: advice is retry, connect in 4.459 seconds
Jan 12 01:45:41 squeezeplay: WARN net.thread - NetworkThread.lua:146 network thread timeout for Task(SocketTcp {SlimProto}(W))
Jan 12 01:45:41 squeezeplay: INFO net.slimproto - SlimProto.lua:769 connection error: inactivity timeout, reconnecting in 4.776 seconds
Jan 12 01:45:49 squeezeplay: WARN net.comet - Comet.lua:888 Comet {mysqueezebox.com}: _response, /meta/reconnect id=nil failed: invalid clientId
Jan 12 01:45:49 squeezeplay: INFO net.comet - Comet.lua:1006 Comet {mysqueezebox.com}: handleAdvice state=CONNECTING
Jan 12 01:45:49 squeezeplay: INFO squeezebox.server - SlimServer.lua:789 disconnected mysqueezebox.com idleTimeoutTriggered: nil
Jan 12 01:45:49 squeezeplay: INFO applet.AlarmSnooze - AlarmSnoozeApplet.lua:379 notify_serverDisconnected: SlimServer {mysqueezebox.com} is now disconnected
Jan 12 01:45:49 squeezeplay: WARN applet.AlarmSnooze - AlarmSnoozeApplet.lua:392 notify_serverDisconnected: SlimServer {mysqueezebox.com} - disconnected, but no server alarm in progress : nil
Jan 12 01:45:49 squeezeplay: INFO net.comet - Comet.lua:1047 Comet {mysqueezebox.com}: advice is handshake, connect in 0 seconds
Jan 12 01:45:49 squeezeplay: INFO net.slimproto - SlimProto.lua:592 connect to baby.squeezenetwork.com (54.246.73.168)
Jan 12 01:45:49 squeezeplay: INFO net.slimproto - SlimProto.lua:152 Send HELO: reconnect-bit=0 bytesReceived(H,L)=0,3333088
Jan 12 01:45:49 squeezeplay: INFO squeezebox.server - SlimServer.lua:765 connected mysqueezebox.com
Jan 12 01:45:49 squeezeplay: INFO applet.AlarmSnooze - AlarmSnoozeApplet.lua:360 notify_serverConnected: SlimServer {mysqueezebox.com} is now connected

Eisbaer2
2018-01-12, 07:32
I tried to reproduce your log [...] The "frozen" seems to be the result of some sort of network issue. I think SBR is "frozen" because it is waiting while trying to set up communication with mysqeezebox.com.

Thanks again! The strange thing is that the SBR is *always* controllable via mysqeezebox.com and via the Squeeze Controller app (Android).


When you say SBR is frozen - how long did you wait before doing other tasks to get SBR "working" ?

Differently. Usually when I notice the freeze (after switching on or after changing to another station) I immediately reboot my SBR. But not always.


When in a frozen state - if you wait more than 1 mins and then press Preset button again - does SBR work ?

No. I can wait forever (ok, never tried that so far ;-). But even after hours in the frozen state there is no self-healing effect. Only chance to heal I found so far is to reboot.


The issues is to determine if the problem connecting to mysqueezebox.com is a network issue between router and ISP or a network issue inside SBR ?

How can I determine that?
After the next freezing I plan to connect my SBR to a LAN cable for several days and see if the problem still occurs. I only don't have LAN at the usual location of the SBR.

By the way: you mentioned to uninstall applets. I think no applets are installed.

bpa
2018-01-12, 08:36
How can I determine that?
After the next freezing I plan to connect my SBR to a LAN cable for several days and see if the problem still occurs. I only don't have LAN at the usual location of the SBR.

By the way: you mentioned to uninstall applets. I think no applets are installed.

The more I look at the log - the more it looks like everything is "normal" (i.e. I have seen similar logged messages on my SBR after connecting/disconnecting LMS / mysqeueezebox.com ) - just there is some sort of network disruption which needs to be characterised before it can be fixed.

The usual way to get jmore info is to enable better logging through SBR Menu Settings/Advanced/Logging

If squeezebox.server is set to DEBUG - the status of LMS / mysqueezebox.com connection is shown at intervals and if it changes messages are logged.

To see the state of the network connections you could enable net.socket to DEBUG but this generates lots of messages but it should "pinpoint" any Wifi disconnection issue.

I'd advise try setting squeezebox.server to DEBUG first.

I

Eisbaer2
2018-01-16, 01:09
The more I look at the log - the more it looks like everything is "normal" (i.e. I have seen similar logged messages on my SBR after connecting/disconnecting LMS / mysqeueezebox.com ) - just there is some sort of network disruption which needs to be characterised before it can be fixed.

The usual way to get jmore info is to enable better logging through SBR Menu Settings/Advanced/Logging

If squeezebox.server is set to DEBUG - the status of LMS / mysqueezebox.com connection is shown at intervals and if it changes messages are logged.

To see the state of the network connections you could enable net.socket to DEBUG but this generates lots of messages but it should "pinpoint" any Wifi disconnection issue.

I'd advise try setting squeezebox.server to DEBUG first.

I

Short update: As suggested I enabled the DEBUG mode for net.socket and squeezebox.server. Until now I've had no more freezes for about 4 days. Great! :)
I only have a new phenomenon: often the wrong web radio logo is shown. That can be solved by pressing FR or FF several times. Doesn't bother me much.

bpa
2018-01-16, 01:29
Short update: As suggested I enabled the DEBUG mode for net.socket and squeezebox.server. Until now I've had no more freezes for about 4 days. Great! :)
I only have a new phenomenon: often the wrong web radio logo is shown. That can be solved by pressing FR or FF several times. Doesn't bother me much.

Enabling logging should not fix a problem - it has just changed the symptoms.

The image issues sounds like the network request/response for new image is getting "lost" in your network connection and the FF/FR is just a manual way of repeating the requests. IIRC mysqueezebox.com does the image resizing - long delays can happen.

Eisbaer2
2018-01-16, 13:39
Enabling logging should not fix a problem - it has just changed the symptoms.

The image issues sounds like the network request/response for new image is getting "lost" in your network connection and the FF/FR is just a manual way of repeating the requests. IIRC mysqueezebox.com does the image resizing - long delays can happen.

Unfortunately the freeze happened again. About an hour ago everything went fine. Then changing web radio stations took longer and longer. And finally it froze. But it is still possible to remote control it via mysqueezebox.com.

Attached the current log files: 24405

bpa
2018-01-17, 04:48
The logs are too short - only 10 mins and I don't know time frame of "took longer & longer"

The DEBUG setting has shown network connections is OK but connection to server drops and also another message has appeared


Jan 16 21:32:49 squeezeplay: DEBUG squeezebox.server - SlimServer.lua:775 arp: arp 192.168.178.31: Cannot allocate memory
.
.
.
Jan 16 21:32:50 squeezeplay: DEBUG squeezebox.server - SlimServer.lua:775 arp: arp baby.squeezenetwork.com: Cannot allocate memory

I need to run tests to see if this is "normal" or specific to your setup.

If it is specific to your network - it would indicate a gradual loss of free memory which typically ends up with a blocked system.

arp is related to networks -
How does your server suspend LMS ? is it a whole system shutdown ?
Do you have a simple network (i.e single router) or a complex one with, for example, any of the following: mulitple routers, APs, bridges, VLANs, VPNs, MAC spoofing, dynamic reconfiguration etc.

ralphy
2018-01-17, 05:39
The logs are too short - only 10 mins and I don't know time frame of "took longer & longer"

The DEBUG setting has shown network connections is OK but connection to server drops and also another message has appeared


Jan 16 21:32:49 squeezeplay: DEBUG squeezebox.server - SlimServer.lua:775 arp: arp 192.168.178.31: Cannot allocate memory
.
.
.
Jan 16 21:32:50 squeezeplay: DEBUG squeezebox.server - SlimServer.lua:775 arp: arp baby.squeezenetwork.com: Cannot allocate memory

I need to run tests to see if this is "normal" or specific to your setup.

If it is specific to your network - it would indicate a gradual loss of free memory which typically ends up with a blocked system.

arp is related to networks -
How does your server suspend LMS ? is it a whole system shutdown ?
Do you have a simple network (i.e single router) or a complex one with, for example, any of the following: mulitple routers, APs, bridges, VLANs, VPNs, MAC spoofing, dynamic reconfiguration etc.

The arp command is spawned as a process from jive/net/NetworkThread.lua.

bpa
2018-01-17, 05:58
The arp command is spawned as a process from jive/net/NetworkThread.lua.

I expected that - the question is whether "cannot allocate memory" is normal ? It is a DEBUG level - I would have thought an error from arp would have been logged as ERROR not DEBUG.

Eisbaer2
2018-01-17, 06:45
The logs are too short - only 10 mins and I don't know time frame of "took longer & longer"

I don't know why but putty stops to show (and log) anything in the terminal window after about 5-10 minutes. And the log files on my SBR aren't longer also.


How does your server suspend LMS ? is it a whole system shutdown ?

It is a scheduled daily shutdown of the NAS (synology). Don't know what exactly happens with the LMS package during shutdown.


Do you have a simple network (i.e single router) or a complex one with, for example, any of the following: mulitple routers, APs, bridges, VLANs, VPNs, MAC spoofing, dynamic reconfiguration etc.

It this: NAS <LAN> TP-Link Gigabit Switch <LAN> Fritzbox Router <WIFI> SBR
There is no MAC spoofing, no VPN, no dynamic reconfiguration.

Eisbaer2
2018-01-17, 06:47
Unfortunately the freeze happened again. About an hour ago everything went fine. Then changing web radio stations took longer and longer. And finally it froze. But it is still possible to remote control it via mysqueezebox.com.

Update: I didn't reboot after the lagging / the freeze yesterday. Today everything was fine again. Never happend before. Maybe it was because I connected to my SBR via mysqueezebox.com and remotely switched favorite stations. I'll try that again after next freezing again.

bpa
2018-01-17, 08:36
I don't know why but putty stops to show (and log) anything in the terminal window after about 5-10 minutes. And the log files on my SBR aren't longer also.

That is strange. That "feels" like a power save feature kicking in or else network connection gets interrupted - what version of putty and on what OS so I can check and see iof there any putty diagnostics that can be enabled..

Eisbaer2
2018-01-17, 08:48
That is strange. That "feels" like a power save feature kicking in or else network connection gets interrupted - what version of putty and on what OS so I can check and see iof there any putty diagnostics that can be enabled..

putty 0.68, windows 10 (1709), keepalive (null) packets are sent every 30 seconds

bpa
2018-01-19, 05:26
Not sure if this is progress.

The issues about putty stopping logging message - I have duplicated this and it is not a putty issue. On Radio to conserve log message space it cycle log file, after about 10 mins messages gets rename to messages.0 and a new messages is opened. The "tail -f" is still tied to messages.0 and so no new messages are added.

I have had a sort of "frozen" event - it looks like Radio has somehow reverted from MYSB.com to local LMS - however after repeated pressing of preset - station was played via mysb.com so not quite the same as yoru "frozen".

The error - "cannot allocate memory" does not occur on my Radio so I hope this is indicator of something. The Radio source routine which produces the error is below - it is a request to find the MAC address of the LMS or maybe MYSB.com. arp request is supposed to be run as a process so the "cannot allocate memory" could be either from the failure to create a new process or the failure of the arp command.



-- comet has connected to SC
function notify_cometConnected(self, comet)
if self.comet ~= comet then
return
end

log:info("connected ", self.name)

self.netstate = 'connected'
self.jnt:notify('serverConnected', self)

self.authFailureCount = 0

-- auto discovery SqueezeCenter's mac address
self.jnt:arp(self.ip, function(chunk, err)
if err then
log:debug("arp: " .. err)
else
log:info('self.mac being set to---->', self.mac)
self.mac = chunk
end
end)
end

Eisbaer2
2018-01-19, 05:36
Not sure if this is progress.

The issues about putty stopping logging message - I have duplicated this and it is not a putty issue. On Radio to conserve log message space it cycle log file, after about 10 mins messages gets rename to messages.0 and a new messages is opened. The "tail -f" is still tied to messages.0 and so no new messages are added. [QUOTE]

Understooden. So there is no possibility to do a long-term logging?

[QUOTE=bpa;904661]I have had a sort of "frozen" event - it looks like Radio has somehow reverted from MYSB.com to local LMS - however after repeated pressing of preset - station was played via mysb.com so not quite the same as yoru "frozen".

The error - "cannot allocate memory" does not occur on my Radio so I hope this is indicator of something. The Radio source routine which produces the error is below - it is a request to find the MAC address of the LMS or maybe MYSB.com. arp request is supposed to be run as a process so the "cannot allocate memory" could be either from the failure to create a new process or the failure of the arp command.

I'm sorry I don't fully understand that. Do you have any ideas what I could do then?

By the way: after the last surprising "self healing" two days ago I didn't have any further freezes yet :)

bpa
2018-01-19, 06:50
Understooden. So there is no possibility to do a long-term logging?
it's possible but it would need a little script to copy messages.0 at regular intervals (i.e. 10 min snapshots) and append/removing duplicates.
For the moment, the issue is understood and if we need longer logs - there is a way.


I'm sorry I don't fully understand that. Do you have any ideas what I could do then?
I'm not sure if "cant allocate memory" is a cause or a result of the "frozen" state. I'm going to check out the similar short lived "frozen" issue I saw on my Radio and understand it because it "feels" very similar to yours.


By the way: after the last surprising "self healing" two days ago I didn't have any further freezes yet :)
Takes the immediate pressure off.

pablolie
2018-01-25, 00:33
For what it's worth...

I started having 15s dropouts as soon as I synched playback between my Touch, Boom and Radio. I detected that as soon as I took the radio out of the synch, things worked fine. I also determined wireless connectivity was not the culprit.

I simply re-installed the Radio firmware. The exact same version. Oddly enough that fixed it. Three way synch all day, no issues.

Eisbaer2
2018-01-25, 01:38
For what it's worth...

I started having 15s dropouts as soon as I synched playback between my Touch, Boom and Radio. I detected that as soon as I took the radio out of the synch, things worked fine. I also determined wireless connectivity was not the culprit.

I simply re-installed the Radio firmware. The exact same version. Oddly enough that fixed it. Three way synch all day, no issues.

Thanks for this information. In my case only:
- there is only one device (SBR) and a LMS, so there is no sync.
- I already re-installed the newest firmware and already downgraded to an older firmware. Without any success. (upgraded again to the newest firmware after several freezes)
So I don't think that will help me.

But I'm glad at the moment. Haven't had any freezes for a week now. Incredible! :D

DrJohn
2018-01-27, 05:08
Hi, just out of curiosity: Do you have a Google chromecast or some other Google home device in your network?

I also had issues with freezing radios (though with some other symptoms), which were caused by a chromecast bug: http://forums.slimdevices.com/showthread.php?108455-Squeezebox-Radio-slows-down-dramatically-and-does-notconnect-to-server-till-restart

The bug fix is currently being rolled out, so that would explain why you don't have issues anymore.

bpa
2018-01-27, 05:16
Details on Chromecast bug below but I don't this is the issues

https://support.google.com/chromecast/answer/7634752?vid=0-1095984840784-1516229539273

Eisbaer2
2018-01-27, 23:14
Hi, just out of curiosity: Do you have a Google chromecast or some other Google home device in your network?

Thank you for the information.
No, I don't have any chromecast devices in my network.