search

pimusicbox / pimusicbox

An image (SD-card) to turn the Raspberry Pi into an easy to use MusicBox with Spotify playback and AirTunes streaming
http://www.pimusicbox.com
Apache License 2.0
2.03k stars 218 forks source link

Bug: Crashing when spotify continues #346

Open clausfuglsang opened 8 years ago

clausfuglsang commented 8 years ago

After I stop playing music from spotify, which basically works fine, the Musicbox will crash if I leave it for more than an hour or so, and then wants to continue playing music again. If i stop playing, and I get back to it an hour later, I need to reboot it manually if I want to play from spotify again. I only use spotify, so i am not aware of if the problem is the same with the other services.

If i pause a song for 5 minutes, and continue the song, there is no issue.

I've had this issue for 1½ years now. I'm running the latest release of Musicbox. Great work though, love the features.

jcass77 commented 8 years ago

Could you perhaps take a look at /var/log/mopidy/mopidy.log and post any relevant error messages contained therein?

Does it work if you do service mopidy restart instead of a full reboot of the Musicbox?

kingosticks commented 8 years ago

And, just to clarify, when you say 'stop' do you mean pause?

lukyluke112 commented 8 years ago

Have the same issue

lukyluke112 commented 8 years ago

And with me it just won't play anything

kingosticks commented 8 years ago

If you don't post your logs there is literally nothing to go on.

lukyluke112 commented 8 years ago

Bit of a noob looked for log file do you use a different name for the log file

B3nihana commented 8 years ago

I have the same issue also, as I use MusicBox infrequently but solely for Spotify. I am still able to restart MB via the web UI but its very slow to respond (UI very sluggish to load menus, will play songs like there is no bandwidth).

I'll be sure to get the log next time this happens, I'm just so used to rebooting it now!

Original Pi B+ btw

B3nihana commented 8 years ago

Ok, so this issue happened again and I remember to grab the log.

Basically I start to play a spotify playlist, then pause it after several hours and try to unpause it the next day and nothing happens. I can navigate the GUI but searching for music or trying to start a new playlist results in a spinning busy icon. Sometimes it will start working 30 minutes later, but usually I simply restart and it works.

@lukyluke112 The log folder is under the var folder, called monit.log. Under the Mopidy folder there is a 2nd log.

@kingosticks Hope this helps: Monit.log [UTC`` Apr 17 13:08:21] info : 'mopidy' trying to restart [UTC Apr 17 13:08:21] info : 'mopidy' stop: /etc/init.d/mopidy [UTC Apr 17 13:08:51] info : 'mopidy' start: /etc/init.d/mopidy [UTC Apr 17 13:10:51] info : 'mopidy' connection succeeded to INET[localhost:6680] via TCP [UTC Apr 17 16:06:38] info : monit daemon with pid [2478] killed [UTC Apr 17 16:06:38] info : 'system_MusicBox' Monit stopped [UTC Apr 17 16:07:15] info : Starting monit daemon [UTC Apr 17 16:07:15] info : Monit start delay set -- pause for 300s [UTC Apr 17 16:12:15] info : 'system_MusicBox' Monit started [UTC Apr 18 12:05:40] info : monit daemon with pid [2480] killed [UTC Apr 18 12:05:40] info : 'system_MusicBox' Monit stopped [UTC Apr 18 12:06:42] info : Starting monit daemon [UTC Apr 18 12:06:42] info : Monit start delay set -- pause for 300s [UTC Apr 18 12:11:42] info : 'system_MusicBox' Monit started [UTC Apr 24 08:07:17] info : monit daemon with pid [2488] killed [UTC Apr 24 08:07:17] info : 'system_MusicBox' Monit stopped [UTC Apr 24 08:07:55] info : Starting monit daemon [UTC Apr 24 08:07:55] info : Monit start delay set -- pause for 300s [UTC Apr 24 08:12:55] info : 'system_MusicBox' Monit started [UTC Apr 25 11:45:46] error : 'upmpdcli' process is not running [UTC Apr 25 11:45:46] info : 'upmpdcli' trying to restart [UTC Apr 25 11:45:46] info : 'upmpdcli' start: /etc/init.d/upmpdcli [UTC Apr 25 11:47:46] info : 'upmpdcli' process is running with pid 3066 [UTC Apr 29 17:48:54] error : 'upmpdcli' process is not running [UTC Apr 29 17:48:54] info : 'upmpdcli' trying to restart [UTC Apr 29 17:48:54] info : 'upmpdcli' start: /etc/init.d/upmpdcli [UTC Apr 29 17:50:54] info : 'upmpdcli' process is running with pid 5317 [UTC May 4 05:17:30] info : Starting monit daemon [UTC May 4 05:17:30] info : Monit start delay set -- pause for 300s [UTC May 4 05:22:30] info : 'system_MusicBox' Monit started [UTC May 10 07:36:18] error : 'mopidy' process is not running [UTC May 10 07:36:18] info : 'mopidy' trying to restart [UTC May 10 07:36:18] info : 'mopidy' start: /etc/init.d/mopidy [UTC May 10 07:38:18] info : 'mopidy' process is running with pid 3691 [UTC May 11 06:27:07] error : 'mopidy' failed protocol test [HTTP] at INET[localhost:6680] via TCP -- HTTP: Error receiving data -- Resource temporarily unavailable [UTC May 11 06:29:12] error : 'mopidy' failed protocol test [HTTP] at INET[localhost:6680] via TCP -- HTTP: Error receiving data -- Resource temporarily unavailable [UTC May 11 06:29:12] info : 'mopidy' trying to restart [UTC May 11 06:29:12] info : 'mopidy' stop: /etc/init.d/mopidy [UTC May 11 06:29:42] info : 'mopidy' start: /etc/init.d/mopidy [UTC May 11 06:31:43] info : 'mopidy' connection succeeded to INET[localhost:6680] via TCP

Mopidy.log 2016-05-11 06:29:46,473 - INFO Starting Mopidy 0.19.5 2016-05-11 06:29:48,592 - INFO Loading config from: builtin defaults, /etc/mopidy/extensions.d/spotify.conf, /etc/mopidy/mopidy.conf, command line options 2016-05-11 06:29:50,262 - INFO Enabled extensions: mopify, spotify, mpd, http, stream, spotify_tunigo, mobile, podcast-gpodder, local-sqlite, youtube, podcast-itunes, http-kuechenradio, scrobbler, simple-webclient, softwaremixer, local-whoosh, dirble, moped, websettings, podcast, tunein 2016-05-11 06:29:50,265 - INFO Disabled extensions: alsamixer, gmusic, somafm, subsonic, internetarchive, audioaddict, musicbox_webclient, local, soundcloud 2016-05-11 06:29:50,268 - WARNING Found alsamixer configuration errors, the extension has been automatically disabled: 2016-05-11 06:29:50,271 - WARNING alsamixer/control must be set. 2016-05-11 06:29:50,274 - WARNING alsamixer/card must be set. 2016-05-11 06:29:50,276 - WARNING Found musicbox_webclient configuration errors, the extension has been automatically disabled: 2016-05-11 06:29:50,279 - WARNING musicbox_webclient/musicbox unknown config key. 2016-05-11 06:29:50,282 - WARNING Please fix the extension configuration errors or disable the extensions to silence these messages. 2016-05-11 06:30:07,956 - INFO Starting Mopidy mixer: SoftwareMixer 2016-05-11 06:30:07,963 - INFO Mixing using GStreamer software mixing 2016-05-11 06:30:07,976 - INFO Mixer volume set to 85 2016-05-11 06:30:07,980 - INFO Starting Mopidy audio 2016-05-11 06:30:07,997 - INFO Starting Mopidy backends: SpotifyTunigoBackend, TuneInBackend, StreamBackend, PodcastBackend, YoutubeBackend, SpotifyBackend, DirbleBackend 2016-05-11 06:30:08,150 - INFO Audio output set to "alsasink" 2016-05-11 06:30:08,299 - INFO Starting Mopidy-Podcast directories: iTunesDirectory, FeedsDirectory, GPodderDirectory 2016-05-11 06:30:08,333 - INFO Refreshing Mopidy-Podcast directories 2016-05-11 06:30:08,412 - INFO Starting new HTTP connection (1): itunes.apple.com 2016-05-11 06:30:08,516 - INFO Mopidy uses SPOTIFY(R) CORE 2016-05-11 06:30:08,647 - INFO Starting Mopidy core 2016-05-11 06:30:09,136 - INFO Starting Mopidy frontends: MpdFrontend, HttpFrontend, ScrobblerFrontend 2016-05-11 06:30:09,152 - INFO MPD server running at [::ffff:0.0.0.0]:6600 2016-05-11 06:30:09,181 - INFO HTTP server running at [::ffff:0.0.0.0]:6680 2016-05-11 06:30:09,933 - INFO Scrobbler connected to Last.fm 2016-05-11 06:30:10,439 - INFO Connected to Spotify 2016-05-11 06:30:11,271 - INFO New MPD connection from [::ffff:127.0.0.1]:60441 2016-05-11 06:30:28,905 - INFO Loaded 31 Spotify playlists 2016-05-11 06:31:43,277 - INFO 200 GET / (127.0.0.1) 108.47ms 2016-05-11 06:33:43,333 - INFO 200 GET / (127.0.0.1) 14.96ms 2016-05-11 06:35:43,388 - INFO 200 GET / (127.0.0.1) 14.72ms 2016-05-11 06:37:43,446 - INFO 200 GET / (127.0.0.1) 14.86ms 2016-05-11 06:39:43,501 - INFO 200 GET / (127.0.0.1) 14.69ms 2016-05-11 06:41:43,563 - INFO 200 GET / (127.0.0.1) 21.08ms 2016-05-11 06:43:43,613 - INFO 200 GET / (127.0.0.1) 14.67ms 2016-05-11 06:45:43,668 - INFO 200 GET / (127.0.0.1) 14.43ms 2016-05-11 06:47:43,725 - INFO 200 GET / (127.0.0.1) 14.21ms 2016-05-11 06:49:43,782 - INFO 200 GET / (127.0.0.1) 15.23ms 2016-05-11 06:51:43,837 - INFO 200 GET / (127.0.0.1) 14.40ms 2016-05-11 06:53:43,893 - INFO 200 GET / (127.0.0.1) 14.77ms 2016-05-11 06:55:43,952 - INFO 200 GET / (127.0.0.1) 17.65ms 2016-05-11 06:57:44,053 - INFO 200 GET / (127.0.0.1) 29.91ms 2016-05-11 06:59:44,106 - INFO 200 GET / (127.0.0.1) 14.33ms 2016-05-11 07:01:44,162 - INFO 200 GET / (127.0.0.1) 14.77ms 2016-05-11 07:03:44,218 - INFO 200 GET / (127.0.0.1) 14.48ms 2016-05-11 07:05:44,274 - INFO 200 GET / (127.0.0.1) 15.16ms 2016-05-11 07:07:44,386 - INFO 200 GET / (127.0.0.1) 31.09ms 2016-05-11 07:09:44,430 - INFO 200 GET / (127.0.0.1) 14.61ms 2016-05-11 07:11:44,486 - INFO 200 GET / (127.0.0.1) 14.69ms 2016-05-11 07:13:44,542 - INFO 200 GET / (127.0.0.1) 15.27ms 2016-05-11 07:13:55,134 - INFO Loaded 31 Spotify playlists 2016-05-11 07:15:44,601 - INFO 200 GET / (127.0.0.1) 16.78ms 2016-05-11 07:17:44,657 - INFO 200 GET / (127.0.0.1) 14.35ms 2016-05-11 07:19:44,714 - INFO 200 GET / (127.0.0.1) 15.15ms 2016-05-11 07:21:44,772 - INFO 200 GET / (127.0.0.1) 14.99ms 2016-05-11 07:23:44,829 - INFO 200 GET / (127.0.0.1) 14.35ms 2016-05-11 07:25:44,887 - INFO 200 GET / (127.0.0.1) 14.37ms 2016-05-11 07:27:44,944 - INFO 200 GET / (127.0.0.1) 15.18ms 2016-05-11 07:29:40,221 - INFO 304 GET /images/icons/pause_32x32.png (192.168.1.34) 58.29ms 2016-05-11 07:29:40,376 - INFO 200 GET /images/icons/play_alt_12x12.png (192.168.1.34) 50.37ms 2016-05-11 07:29:45,023 - INFO 200 GET / (127.0.0.1) 17.77ms 2016-05-11 07:31:45,088 - INFO 200 GET / (127.0.0.1) 17.16ms 2016-05-11 07:33:45,156 - INFO 200 GET / (127.0.0.1) 18.78ms 2016-05-11 07:35:45,272 - INFO 200 GET / (127.0.0.1) 32.83ms 2016-05-11 07:37:45,382 - INFO 200 GET / (127.0.0.1) 21.83ms 2016-05-11 07:39:00,775 - INFO 304 GET /images/icons/play_alt_32x32.png (192.168.1.34) 105.35ms 2016-05-11 07:39:00,876 - INFO 304 GET /images/default_cover.png (192.168.1.34) 69.91ms 2016-05-11 07:39:01,209 - INFO 304 GET /images/icons/pause_32x32.png (192.168.1.34) 128.83ms 2016-05-11 07:39:45,561 - INFO 200 GET / (127.0.0.1) 71.53ms 2016-05-11 07:41:45,617 - INFO 200 GET / (127.0.0.1) 17.70ms 2016-05-11 07:42:12,766 - INFO 304 GET /images/icons/play_alt_32x32.png (192.168.1.34) 36.17ms 2016-05-11 07:42:12,920 - INFO 304 GET /images/default_cover.png (192.168.1.34) 80.46ms 2016-05-11 07:42:13,229 - INFO 304 GET /images/icons/pause_32x32.png (192.168.1.34) 41.58ms 2016-05-11 07:43:45,683 - INFO 200 GET / (127.0.0.1) 18.80ms 2016-05-11 07:45:18,321 - INFO 304 GET /images/default_cover.png (192.168.1.34) 82.82ms 2016-05-11 07:45:18,398 - INFO 304 GET /images/icons/play_alt_32x32.png (192.168.1.34) 57.46ms 2016-05-11 07:45:18,566 - INFO 304 GET /images/icons/pause_32x32.png (192.168.1.34) 38.26ms 2016-05-11 07:45:45,750 - INFO 200 GET / (127.0.0.1) 18.57ms 2016-05-11 07:47:37,347 - INFO 304 GET /images/icons/play_alt_32x32.png (192.168.1.34) 14.70ms 2016-05-11 07:47:45,809 - INFO 200 GET / (127.0.0.1) 15.83ms 2016-05-11 07:49:45,866 - INFO 200 GET / (127.0.0.1) 14.20ms 2016-05-11 07:51:46,018 - INFO 200 GET / (127.0.0.1) 46.41ms 2016-05-11 07:52:10,622 - INFO 304 GET /images/default_cover.png (192.168.1.34) 43.26ms 2016-05-11 07:53:46,073 - INFO 200 GET / (127.0.0.1) 18.34ms 2016-05-11 07:55:46,135 - INFO 200 GET / (127.0.0.1) 15.07ms 2016-05-11 07:57:23,657 - INFO 304 GET /images/icons/play_alt_32x32.png (192.168.1.34) 43.15ms 2016-05-11 07:57:23,766 - INFO 304 GET /images/default_cover.png (192.168.1.34) 69.07ms 2016-05-11 07:57:46,201 - INFO 200 GET / (127.0.0.1) 17.33ms 2016-05-11 07:59:46,346 - INFO 200 GET / (127.0.0.1) 55.81ms 2016-05-11 08:01:46,429 - INFO 200 GET / (127.0.0.1) 22.53ms 2016-05-11 08:03:46,552 - INFO 200 GET / (127.0.0.1) 38.37ms

kingosticks commented 8 years ago

Thanks for providing your log unfortunately the LOG_LEVEL is too high to show anything interesting. The problem with increasing the verbosity is that over time it's a great way to wear out your SD card so it's not advisable in the long-term. However, if you have a way to reliably recreate this problem then you could try temporarily setting level = DEBUG in /etc/mopidy/mopidy.log.

When Mopidy crashes, depending on your browser, you may still be able to navigate the web UI since it's cached by your browser; but anything action that requires new response data will fail and you'll get the spinning icon.

Can you just clarify when you paused and unpaused, particularly in relation to the events in monit.log.