Great software has been working fantastically with my Raspberry Pi B 1 and a Wolfson Audio card from NAS, Spotify and YouTube, until this latest update.
Symptoms:
Select an album to play from NAS (SMB) by searching and using “Clear and Play” - album starts to play the first track, but as soon as play starts the web UI dispalys the spinning wait symbol and any interaction is impossible. Only the first song is played, after it is finished the web UI is usable. Any single song from the queue can be played with the same symptoms of apparent hangin of UI during playing.
But select an album to play from Spotify by the same method and the entire album is played, with the UI being opperational while the song is playing.
Been experiencing the same issue here. I have a similar setup using the wolfson/cirrus DAC w/RPi B3. However it seems to be unrelated to setup as others have experienced similar issues:
Just out of curiosity, do you use airplay? And have you had any troubles with it since this last issue started happening? I’m going to try a fresh install to see if the problem persists but just curious.
Volumio log is a bit confusing, as it is successfully playing a single track from my NAS, with the Web GUI having hung, but then is reporting it can’t mount the NAS and what I assume is the real problem “TypeError: Cannot read property ‘0’ of undefined”.
Log with single track playing and webgui unresponsive (circling):
[spoiler][1515793082101] ---------------------------- MPD announces state update: player
2018-01-12T21:38:02.123Z - info: [1515793082121] ControllerMpd::getState
2018-01-12T21:38:02.126Z - info: [1515793082124] ControllerMpd::sendMpdCommand status
2018-01-12T21:38:02.155Z - info: [1515793082128] parsing response…
2018-01-12T21:38:02.166Z - info: [1515793082160] sending command…
2018-01-12T21:38:02.186Z - info: [1515793082180] ControllerMpd::parseState
2018-01-12T21:38:02.209Z - info: [1515793082190] ControllerMpd::sendMpdCommand playlistinfo
2018-01-12T21:38:02.216Z - info: [1515793082211] sending command…
2018-01-12T21:38:02.289Z - info: [1515793082275] parsing response…
2018-01-12T21:38:02.309Z - info: [1515793082291] parsing response…
2018-01-12T21:38:02.318Z - info: [1515793082312] ControllerMpd::parseState
2018-01-12T21:38:02.326Z - info: [1515793082320] ControllerMpd::sendMpdCommand playlistinfo
2018-01-12T21:38:02.359Z - info: [1515793082345] ControllerMpd::parseTrackInfo
2018-01-12T21:38:02.368Z - info: [1515793082363] sending command…
2018-01-12T21:38:02.386Z - info: [1515793082380] ControllerMpd::pushState
2018-01-12T21:38:02.399Z - info: CoreCommandRouter::servicePushState
2018-01-12T21:38:02.419Z - info: [1515793082400] CoreStateMachine::syncState
2018-01-12T21:38:02.426Z - info: [1515793082420] CorePlayQueue::getTrack 0
2018-01-12T21:38:02.435Z - info: STATE SERVICE {“status”:“play”,“position”:0,“seek”:684,“duration”:246,“samplerate”:“44.1 KHz”,“bitdepth”:“24 bit”,“channels”:2,“random”:false,“updatedb”:false,“repeat”:false,“isStreaming”:false,“title”:“A Prince among Men”,“artist”:“Andy Irvine”,“album”:“Rain on the Roof”,“uri”:“NAS/Music/Music/Simon/Andy Irvine/Rain on the Roof/A Prince among Men.mp3”,“trackType”:“mp3”}
2018-01-12T21:38:02.442Z - info: CURRENT POSITION 0
2018-01-12T21:38:02.459Z - info: [1515793082443] CoreStateMachine::syncState stateService play
2018-01-12T21:38:02.462Z - info: [1515793082460] CoreStateMachine::syncState currentStatus stop
2018-01-12T21:38:02.466Z - info: [1515793082463] CoreStateMachine::pushState
2018-01-12T21:38:02.493Z - info: [1515793082467] CoreStateMachine::getState
2018-01-12T21:38:02.501Z - info: [1515793082495] CorePlayQueue::getTrack 0
2018-01-12T21:38:02.509Z - info: CoreCommandRouter::volumioPushState
2018-01-12T21:38:02.519Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2018-01-12T21:38:02.539Z - info: [1515793082523] interfaceApi::pushState
2018-01-12T21:38:02.546Z - info: [1515793082540] InterfaceWebUI::pushState
2018-01-12T21:38:02.789Z - info: [1515793082777] ------------------------------ 878ms
volumio@study:~$ tail -n 100 /var/log/volumio.log
at emit (/volumio/node_modules/sax/lib/sax.js:640:35)
at emitNode (/volumio/node_modules/sax/lib/sax.js:645:5)
at closeTag (/volumio/node_modules/sax/lib/sax.js:905:7)
at Object.write (/volumio/node_modules/sax/lib/sax.js:1452:13)
at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/xml2js.js:508:31)
at Parser.parseString (/volumio/node_modules/xml2js/lib/xml2js.js:7:59)
at /volumio/app/plugins/music_service/upnp_browser/index.js:586:24
at Request.handleRequestResponse [as _callback] (/volumio/node_modules/unirest/index.js:463:26)
at Request.self.callback (/volumio/node_modules/unirest/node_modules/request/request.js:187:22)
at emitTwo (events.js:106:13)
2018-01-12T21:39:33.791Z - error: TypeError: Cannot read property ‘0’ of undefined
at /volumio/app/plugins/music_service/upnp_browser/index.js:78:63
at /volumio/app/plugins/music_service/upnp_browser/index.js:587:21
at Parser. (/volumio/node_modules/xml2js/lib/xml2js.js:489:18)
at emitOne (events.js:96:13)
at Parser.emit (events.js:188:7)
at Object.onclosetag (/volumio/node_modules/xml2js/lib/xml2js.js:447:26)
at emit (/volumio/node_modules/sax/lib/sax.js:640:35)
at emitNode (/volumio/node_modules/sax/lib/sax.js:645:5)
at closeTag (/volumio/node_modules/sax/lib/sax.js:905:7)
at Object.write (/volumio/node_modules/sax/lib/sax.js:1452:13)
at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/xml2js.js:508:31)
at Parser.parseString (/volumio/node_modules/xml2js/lib/xml2js.js:7:59)
at /volumio/app/plugins/music_service/upnp_browser/index.js:586:24
at Request.handleRequestResponse [as _callback] (/volumio/node_modules/unirest/index.js:463:26)
at Request.self.callback (/volumio/node_modules/unirest/node_modules/request/request.js:187:22)
at emitTwo (events.js:106:13)
2018-01-12T21:39:34.039Z - error: TypeError: Cannot read property ‘0’ of undefined
at /volumio/app/plugins/music_service/upnp_browser/index.js:78:63
at /volumio/app/plugins/music_service/upnp_browser/index.js:587:21
at Parser. (/volumio/node_modules/xml2js/lib/xml2js.js:489:18)
at emitOne (events.js:96:13)
at Parser.emit (events.js:188:7)
at Object.onclosetag (/volumio/node_modules/xml2js/lib/xml2js.js:447:26)
at emit (/volumio/node_modules/sax/lib/sax.js:640:35)
at emitNode (/volumio/node_modules/sax/lib/sax.js:645:5)
at closeTag (/volumio/node_modules/sax/lib/sax.js:905:7)
at Object.write (/volumio/node_modules/sax/lib/sax.js:1452:13)
at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/xml2js.js:508:31)
at Parser.parseString (/volumio/node_modules/xml2js/lib/xml2js.js:7:59)
at /volumio/app/plugins/music_service/upnp_browser/index.js:586:24
at Request.handleRequestResponse [as _callback] (/volumio/node_modules/unirest/index.js:463:26)
at Request.self.callback (/volumio/node_modules/unirest/node_modules/request/request.js:187:22)
at emitTwo (events.js:106:13)
2018-01-12T21:39:34.289Z - error: TypeError: Cannot read property ‘0’ of undefined
at /volumio/app/plugins/music_service/upnp_browser/index.js:78:63
at /volumio/app/plugins/music_service/upnp_browser/index.js:587:21
at Parser. (/volumio/node_modules/xml2js/lib/xml2js.js:489:18)
at emitOne (events.js:96:13)
at Parser.emit (events.js:188:7)
at Object.onclosetag (/volumio/node_modules/xml2js/lib/xml2js.js:447:26)
at emit (/volumio/node_modules/sax/lib/sax.js:640:35)
at emitNode (/volumio/node_modules/sax/lib/sax.js:645:5)
at closeTag (/volumio/node_modules/sax/lib/sax.js:905:7)
at Object.write (/volumio/node_modules/sax/lib/sax.js:1452:13)
at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/xml2js.js:508:31)
at Parser.parseString (/volumio/node_modules/xml2js/lib/xml2js.js:7:59)
at /volumio/app/plugins/music_service/upnp_browser/index.js:586:24
at Request.handleRequestResponse [as _callback] (/volumio/node_modules/unirest/index.js:463:26)
at Request.self.callback (/volumio/node_modules/unirest/node_modules/request/request.js:187:22)
at emitTwo (events.js:106:13)
2018-01-12T21:39:35.832Z - info: [1515793175591] VolumeController::Volume 20
2018-01-12T21:39:35.849Z - info: [1515793175836] CoreStateMachine::pushState
2018-01-12T21:39:35.856Z - info: [1515793175850] CoreStateMachine::getState
2018-01-12T21:39:35.873Z - info: [1515793175858] CorePlayQueue::getTrack 0
2018-01-12T21:39:35.899Z - info: CoreCommandRouter::volumioPushState
2018-01-12T21:39:35.902Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2018-01-12T21:39:35.931Z - info: [1515793175929] interfaceApi::pushState
2018-01-12T21:39:35.935Z - info: [1515793175933] InterfaceWebUI::pushState
2018-01-12T21:39:36.059Z - info: Setting volume on startup at 20
2018-01-12T21:39:36.067Z - info: Connecting to daemon
2018-01-12T21:39:36.589Z - info: [1515793176573] CoreStateMachine::setRepeat null single undefined
2018-01-12T21:39:36.613Z - info: [1515793176590] CoreStateMachine::pushState
2018-01-12T21:39:36.629Z - info: [1515793176614] CoreStateMachine::getState
2018-01-12T21:39:36.635Z - info: [1515793176630] CorePlayQueue::getTrack 0
2018-01-12T21:39:36.643Z - info: CoreCommandRouter::volumioPushState
2018-01-12T21:39:36.660Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2018-01-12T21:39:36.670Z - info: [1515793176664] interfaceApi::pushState
2018-01-12T21:39:36.689Z - info: [1515793176671] InterfaceWebUI::pushState
2018-01-12T21:39:36.735Z - info: [1515793176729] CoreStateMachine::setRandom 1
2018-01-12T21:39:36.742Z - info: [1515793176736] CoreStateMachine::pushState
2018-01-12T21:39:36.759Z - info: [1515793176743] CoreStateMachine::getState
2018-01-12T21:39:36.765Z - info: [1515793176760] CorePlayQueue::getTrack 0
2018-01-12T21:39:36.789Z - info: CoreCommandRouter::volumioPushState
2018-01-12T21:39:36.796Z - info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
2018-01-12T21:39:36.819Z - info: [1515793176801] interfaceApi::pushState
2018-01-12T21:39:36.825Z - info: [1515793176820] InterfaceWebUI::pushState
2018-01-12T21:39:37.009Z - info: Pushing Favourites {“service”:“mpd”,“uri”:“music-library/NAS/Music/Music/Simon/Andy Irvine/Rain on the Roof/A Prince among Men.mp3”,“favourite”:false}
2018-01-12T21:39:37.269Z - info: refresh token again in seconds: 3600
2018-01-12T21:39:37.976Z - info: Cannot mount NAS Music at system boot, trial number 4 ,retrying in 5 seconds
2018-01-12T21:39:38.037Z - info: Pushing Favourites {“service”:“mpd”,“uri”:“music-library/NAS/Music/Music/Simon/Andy Irvine/Rain on the Roof/A Prince among Men.mp3”,“favourite”:false}
2018-01-12T21:39:38.079Z - info: Pushing Favourites {“service”:“mpd”,“uri”:“music-library/NAS/Music/Music/Simon/Andy Irvine/Rain on the Roof/A Prince among Men.mp3”,“favourite”:false}
2018-01-12T21:39:38.623Z - info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
2018-01-12T21:39:38.640Z - info: [1515793178624] CoreMusicLibrary::Adding element Spotify
2018-01-12T21:39:40.005Z - info: FIRST BRANCH
2018-01-12T21:39:42.176Z - info: [LastFM] initializing previous state object.
2018-01-12T21:39:42.949Z - info: Upmpdcli Daemon Started
2018-01-12T21:39:42.969Z - info: [1515793182952] Shairport-Sync Started
2018-01-12T21:39:43.059Z - info: Cannot mount NAS at system boot, trial number 4 ,stopping
2018-01-12T21:39:43.549Z - info: mDNS: Found device study[/spoiler]
The issue seems to arise from updating the OS from previous version. Although not ideal all issues playing local media and Airplaying disappeared after a clean install!
Thanks for suggestions, I backed up one of my systems and then went to System - Delete User Data, this deletes all user data plugins, libraries and re-runs the first run wizard, so I have to reinstall the Wolfson stuff, but it also solves the issues .
I will now compare my 2 systems to see if I can spot at obviously setting change which causes the issue and find a simpler solution.
My problem seems to have been caused by the Last FM plugin - I had a working reinitialised system which started hanging when I installed the Last FM plugin, having switched Last FM to be inactive on both systems both now appear to be working.
Thanks! Noticed that after reinstalling plugins that the problem reappeared. Searched the forums and came across the post as well but I guess you beat me to posting it
Might try the fix later on in the week if I have the time otherwise might just wait till it gets updated in the repo.
.
I will now compare my 2 systems to see if I can spot at obviously setting change which causes the issue and find a simpler solution.