Squeezebox Radios Reboots, with talk radio in the UK, cable connected , cable connect

[KeBul]

LBC stream still going after 4 hours 5 minutes

I fired up a spare Radio and kicked off a Classic FM test as well, that's been going 2 hours 5 minutes.

Update,

LBC test Radio playing time reset at 9 hours 15 minutes - although it's set not to resume playing, it did and has now logged another 25 minutes, Radio uptime matches so it must have rebooted, this can't be the timer overflow issue as I did the version comparison fix patch earlier today so it's only been up and running since about 10am.

Classic FM test radio still going at 7 hours 41 minutes.

Kev

[mrw]

The Radio just rebooted playing the stream. Apparently as the OP describes. I don't know why, and will continue in case it was something else, before contemplating further investigation.

Update: No further reboots to report after 6 hours of continuous play. I can rule out the timer overflow issue as the radio had been restarted within a couple of days.

I can see on the Radio that the stream is coming directly from a Global Radio server (as would be expected - player direct streaming is in operation).

[bayard1music]

Hello,

Lots of people now making valuable input. Clearly a number of you have explicit knowledge of how to access the radio and extract further info. (I'd like to understand a bit more about that)

But from what I've read it looks like others have had seen similar reboots. Please correct me if I'm wrong on that. Meaning this is not my radio/network.... Which is good in one sense.

Has any one established any further information from this exercise? Dare I say even a way to prevent it.

[bpa]

But from what I've read it looks like others have had seen similar reboots. Please correct me if I'm wrong on that. Meaning this is not my radio/network.... Which is good in one sense.

AFAICT There were two reboot (1 certain , 2nd implied). Not a large enough sample to be definitive just yet. On the other hand, long playing seems to rule out the know "counter overflow" reboot issue.

edit:

I've started my own non UK test on a Radio, using Tune-in LBC London, wired connection, with "tail -f" on radio /var/log/messages to see if anything logged & maybe catch reboot

BTW - Radio has one MAC address which is either ethernet socket or WLAN but if using ethernet, WLAN processes are still running and so theoretically neighbour's wifi could affect Radio on a wired connection.

[mrw]

Clearly a number of you have explicit knowledge of how to access the radio and extract further info. (I'd like to understand a bit more about that

Enable remote login (an advanced setting on the Radio), and connect with ssh.

But from what I've read it looks like others have had seen similar reboots. Please correct me if I'm wrong on that. Meaning this is not my radio/network.... Which is good in one sense.

I have not become sensitized to an issue like this during the nine years I have been running two Radios. Define "similar reboots".
PS: I don't understand your "meaning".

Has any one established any further information from this exercise? Dare I say even a way to prevent it.

Update: The Radio eventually rebooted after about 9.5 hours of continuous play. The log output (at 'error' level) is not particularly informative, other than it shows us that the main process (jive), died for an unreported reason, and the system then did exactly what it is supposed to do in this circumstance, which is to reboot the Radio.

I'll retry with a higher level of logging to see if we can get a bitter fix on what actually failed. I suppose somewhere in the MP3 audio decoder or in actually fetching (http) the stream.

As for prevention, you could:
A) Try using the AAC stream in preference to the MP3 stream, on the assumption that there is something wrong with the stream that LBC is sending, or the MP3 decoder, or
B) Disable native MP3 - drastic, but ensures LMS fetches the stream rather than the Radio.

The rarity of the error makes it difficult to track down. The only way that I can trigger it right now is to play out the LBC MP3 stream for an unspecified number of hours, and hope for the best. My Radio usually plays soothing music to me during the evening, so this somewhat limits my ability to test.

The log:

jive_alsa notices that jive is dead, and shuts itself down.
Nov 29 02:10:27 squeezeplay: audio_thread_execute:929 exit, parent is dead
Nov 29 02:10:27 squeezeplay: audio_thread_execute:1133 Audio thread exited
The watchdog notices that jive is dead, and runs a logging script prior to rebooting the Radio.
Nov 29 02:10:30 watchdog[688]: pinging process 748 (/var/run/squeezeplay.pid) gave errno = 3 = 'No such process'
Nov 29 02:10:31 root: watchdog error 3
Output by the watchdog logging script - not helpful I think, but I leave it for completeness.
Nov 29 02:10:31 root: 7.7.3 r16676 root@ec2mbubld01.idc.logitech.com Fri Feb 14 09:25:26 PST 2014 Base build revision: bad080aecfec8226a4c1699b29d32cbba4ba396b
Nov 29 02:10:31 root: 02:10:31 up 10:14, load average: 1.07, 1.08, 1.02
Nov 29 02:10:31 root:   PID   TID CLS RTPRIO %CPU %MEM    VSZ   RSS WCHAN           COMMAND
Nov 29 02:10:31 root:     1     1 TS       -  0.0  0.9   2792   584 wait            init
Nov 29 02:10:31 root:     2     2 TS       -  0.0  0.0      0     0 kthreadd        kthreadd
Nov 29 02:10:31 root:     3     3 FF      98  0.0  0.0      0     0 posix_cpu_timer posixcputmr/0
Nov 29 02:10:31 root:     4     4 FF      40  0.0  0.0      0     0 ksoftirqd       sirq-high/0
Nov 29 02:10:31 root:     5     5 FF      40  0.4  0.0      0     0 ksoftirqd       sirq-timer/0
Nov 29 02:10:31 root:     6     6 FF      40  0.0  0.0      0     0 ksoftirqd       sirq-net-tx/0
Nov 29 02:10:31 root:     7     7 FF      40  0.2  0.0      0     0 ksoftirqd       sirq-net-rx/0
Nov 29 02:10:31 root:     8     8 FF      40  0.0  0.0      0     0 ksoftirqd       sirq-block/0
Nov 29 02:10:31 root:     9     9 FF      88  2.0  0.0      0     0 ksoftirqd       sirq-tasklet/0
Nov 29 02:10:31 root:    10    10 FF      40  0.0  0.0      0     0 ksoftirqd       sirq-sched/0
Nov 29 02:10:31 root:    11    11 FF      40  0.0  0.0      0     0 ksoftirqd       sirq-hrtimer/0
Nov 29 02:10:31 root:    12    12 FF      40  0.0  0.0      0     0 ksoftirqd       sirq-rcu/0
Nov 29 02:10:31 root:    13    13 TS       -  0.0  0.0      0     0 -               desched/0
Nov 29 02:10:31 root:    14    14 TS       -  0.0  0.0      0     0 rcu_sched_grace rcu_sched_grace
Nov 29 02:10:31 root:    15    15 FF       1  0.0  0.0      0     0 worker_thread   events/0
Nov 29 02:10:31 root:    16    16 TS       -  0.0  0.0      0     0 worker_thread   khelper
Nov 29 02:10:31 root:    41    41 FF      90  0.5  0.0      0     0 irqd            IRQ-34
Nov 29 02:10:31 root:    67    67 TS       -  0.0  0.0      0     0 worker_thread   kblockd/0
Nov 29 02:10:31 root:    70    70 TS       -  0.0  0.0      0     0 worker_thread   cqueue
Nov 29 02:10:31 root:    78    78 FF      40  0.0  0.0      0     0 irqd            IRQ-3
Nov 29 02:10:31 root:    81    81 FF      40  0.0  0.0      0     0 irqd            IRQ-4
Nov 29 02:10:31 root:    85    85 TS       -  0.0  0.0      0     0 worker_thread   kmmcd
Nov 29 02:10:31 root:   110   110 FF       1  0.0  0.0      0     0 krcupreemptd    krcupreemptd
Nov 29 02:10:31 root:   111   111 TS       -  0.0  0.0      0     0 pdflush         pdflush
Nov 29 02:10:31 root:   112   112 TS       -  0.0  0.0      0     0 pdflush         pdflush
Nov 29 02:10:31 root:   113   113 TS       -  0.0  0.0      0     0 kswapd          kswapd0
Nov 29 02:10:31 root:   114   114 TS       -  0.0  0.0      0     0 worker_thread   aio/0
Nov 29 02:10:31 root:   115   115 TS       -  0.0  0.0      0     0 worker_thread   unionfs_siod/0
Nov 29 02:10:31 root:   120   120 FF      40  0.0  0.0      0     0 irqd            IRQ-39
Nov 29 02:10:31 root:   244   244 FF      40  0.0  0.0      0     0 irqd            IRQ-57
Nov 29 02:10:31 root:   247   247 TS       -  0.0  0.0      0     0 -               mtdblockd
Nov 29 02:10:31 root:   248   248 FF      40  0.0  0.0      0     0 irqd            IRQ-33
Nov 29 02:10:31 root:   280   280 TS       -  0.0  0.0      0     0 ubi_thread      ubi_bgt0d
Nov 29 02:10:31 root:   285   285 FF      40  0.0  0.0      0     0 irqd            IRQ-24
Nov 29 02:10:31 root:   291   291 FF      40  0.0  0.0      0     0 irqd            IRQ-168
Nov 29 02:10:31 root:   292   292 FF      40  0.0  0.0      0     0 irqd            IRQ-167
Nov 29 02:10:31 root:   293   293 FF      40  0.0  0.0      0     0 irqd            IRQ-64
Nov 29 02:10:31 root:   300   300 FF      40  0.0  0.0      0     0 irqd            IRQ-182
Nov 29 02:10:31 root:   304   304 FF      40  0.0  0.0      0     0 irqd            IRQ-46
Nov 29 02:10:31 root:   306   306 FF      40  0.7  0.0      0     0 irqd            IRQ-9
Nov 29 02:10:31 root:   319   319 FF      40  0.0  0.0      0     0 irqd            IRQ-12
Nov 29 02:10:31 root:   327   327 FF      40  0.0  0.0      0     0 irqd            IRQ-166
Nov 29 02:10:31 root:   331   331 FF      50  0.0  0.0      0     0 hrtimer_nanosle loadavg
Nov 29 02:10:31 root:   335   335 FF      40  0.0  0.0      0     0 irqd            IRQ-32
Nov 29 02:10:31 root:   345   345 TS       -  0.0  0.0      0     0 ubifs_bg_thread ubifs_bgt0_2
Nov 29 02:10:31 root:   382   382 TS       -  0.0  1.0   2036   656 select          udevd
Nov 29 02:10:31 root:   665   665 TS       -  0.0  0.8   2800   504 -               syslogd
Nov 29 02:10:31 root:   673   673 TS       -  0.0  0.7   2792   484 syslog          klogd
Nov 29 02:10:31 root:   688   688 RR       1  0.0  2.8   1816  1756 wait            watchdog
Nov 29 02:10:31 root:   690   690 TS       -  0.2  0.4   1624   300 hrtimer_nanosle monitor_msp430
Nov 29 02:10:31 root:   696   696 TS       -  0.0  0.9   2876   616 select          inetd
Nov 29 02:10:31 root:   706   706 TS       -  1.7  0.0      0     0 -               AR6K Async
Nov 29 02:10:31 root:   734   734 FF       1  0.8  0.0      0     0 compat_down_int ksdiorqd
Nov 29 02:10:31 root:   739   739 TS       -  0.6  0.9   2092   604 select          wpa_supplicant
Nov 29 02:10:31 root:   741   741 TS       -  0.0  0.6   1816   380 -               wpa_cli
Nov 29 02:10:31 root:   751   751 TS       -  0.0  0.3   2792   204 read_chan       init
Nov 29 02:10:31 root:   752   752 TS       -  0.0  1.0   2796   636 read_chan       getty
Nov 29 02:10:31 root:   794   794 TS       -  0.0  0.4   2792   256 select          udhcpc
Nov 29 02:10:31 root:  5881  5881 TS       -  0.0  1.7   2584  1096 select          dropbear
Nov 29 02:10:31 root:  5883  5883 TS       -  0.0  0.9   2796   576 wait            sh
Nov 29 02:10:31 root:  5886  5886 TS       -  0.0  0.7   2792   476 -               tail
Nov 29 02:10:31 root:  8199  8199 RR       1  0.0  0.8   2792   536 wait            repair.sh
Nov 29 02:10:31 root:  8205  8205 RR       1  0.0  0.8   2792   508 wait            psall
Nov 29 02:10:31 root:  8206  8206 RR       1  0.0  1.0   2796   664 unix_wait_for_p logger
Nov 29 02:10:31 root:  8207  8207 RR       1  0.0  1.2   2252   752 -               ps
Watchdog reboots system.
Nov 29 02:10:33 watchdog[688]: repair binary returned 3
Nov 29 02:10:33 watchdog[688]: shutting down the system because of error 3
Our remote login window is now closed.
Connection to whiteradio closed by remote host.

[bpa]

I'll retry with a higher level of logging to see if we can get a bitter fix on what actually failed. I suppose somewhere in the MP3 audio decoder or in actually fetching (http) the stream.

If the issues is in the MP3 decoder I think nothing can be done as I think is a 3rd party binary - it doesn't look like it has been updated in Ralphy new radio firmware build https://forums.slimdevices.com/showt...l=1#post995413

[mrw]

If the issues is in the MP3 decoder I think nothing can be done as I think is a 3rd party binary - it doesn't look like it has been updated in Ralphy new radio firmware build https://forums.slimdevices.com/showt...l=1#post995413

I'll check that out.

I suppose that LBC's (Global Radio's) server/streaming processes don't have an infinite life. There may be an awkward interaction when the remote server turns off, or switches over to another server in the farm to service the stream. So, I'm contemplating disabling native MP3, and observing what happens under LMS. The LMS log might tell us something about stream interruption. Thoughts ?

[ralphy]

If the issues is in the MP3 decoder I think nothing can be done as I think is a 3rd party binary - it doesn't look like it has been updated in Ralphy new radio firmware build https://forums.slimdevices.com/showt...l=1#post995413

Yes, that's correct. I only updated the fdk-aac decoder as the logitech firmware uses an older closed source implementation.

I did consider upgrading the mad mp3 decoder as there have been a lot of issues fixed in the last 6 years.

If testing concludes that it's the mp3 decoder causing the reboot then I'll look at updating/fixing it in the community radio firmware.

[mrw]

The log:

Nov 29 02:10:33 watchdog[688]: repair binary returned 3
Nov 29 02:10:33 watchdog[688]: shutting down the system because of error 3

I have noted that the Radio subsequently rebooted itself at 04:56:41. The stream would have been playing after restarting at 02:10, so that suggests a subsequent 'issue' arising within 3 hours. The Radio has been, and is still, playing the stream since 04:56, so it's been going for 9 hours now.

[bpa]

I'll check that out.

I suppose that LBC's (Global Radio's) server/streaming processes don't have an infinite life. There may be an awkward interaction when the remote server turns off, or switches over to another server in the farm to service the stream. So, I'm contemplating disabling native MP3, and observing what happens under LMS. The LMS log might tell us something about stream interruption. Thoughts ?

IIRC Both streamed AAC and MP3 are divided into frames which means audio decoding is done over quite a small amount of data and can be restarted with each frame.

Without knowing Radio internals, as it is the audio execute thread that dies - that points to a problem in audio decoding or possibly internal buffer management (incoming MP3 audio buffer and decoded audio output buffer filling/emptying ). I would think that http is not part of the issue as it is common and so unlikely to be in audio thread - except for adding data to incoming buffer. Similarly metadata will be extracted (and copied to LMS) before adding data to incoming MP3 buffer.