-- Logs begin at Thu 2019-02-14 10:11:59 UTC, end at Wed 2025-03-19 14:41:04 UTC. -- Mar 19 14:40:00 volumio volumio[958]: error: Search in plugin tidal timed out Mar 19 14:40:00 volumio volumio[958]: info: All search sources collected, pushing search results Mar 19 14:40:01 volumio volumio[958]: info: Executing endpoint getSimilarAlbums Mar 19 14:40:01 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 19 14:40:01 volumio volumio[958]: info: Executing endpoint getSimilarAlbums Mar 19 14:40:01 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Mar 19 14:40:01 volumio volumio[958]: info: Executing endpoint metavolumio Mar 19 14:40:01 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 19 14:40:01 volumio volumio[958]: info: Executing endpoint metavolumio Mar 19 14:40:01 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 19 14:40:01 volumio volumio[958]: info: Executing endpoint metavolumio Mar 19 14:40:01 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 19 14:40:01 volumio volumio[958]: info: Executing endpoint metavolumio Mar 19 14:40:01 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Mar 19 14:40:05 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: tidal , search Mar 19 14:40:05 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: tidal , search Mar 19 14:40:05 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: tidal , search Mar 19 14:40:05 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: tidal , search Mar 19 14:40:05 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: tidal , search Mar 19 14:40:05 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: tidal , search Mar 19 14:40:05 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: tidal , search Mar 19 14:40:05 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: tidal , search Mar 19 14:40:05 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: tidal , search Mar 19 14:40:05 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: tidal , search Mar 19 14:40:05 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: tidal , search Mar 19 14:40:05 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 19 14:40:05 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: tidal , search Mar 19 14:40:06 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::volumioGetQueue Mar 19 14:40:06 volumio volumio[958]: info: CoreStateMachine::getQueue Mar 19 14:40:06 volumio volumio[958]: info: CorePlayQueue::getQueue Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::volumioAddQueueItems Mar 19 14:40:06 volumio volumio[958]: info: CoreStateMachine::addQueueItems Mar 19 14:40:06 volumio volumio[958]: info: CorePlayQueue::addQueueItems Mar 19 14:40:06 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:06 volumio volumio[958]: info: Adding Item to queue: spotify:track:3oL3XRtkP1WVbMxf7dtTdu Mar 19 14:40:06 volumio volumio[958]: info: Exploding uri spotify:track:3oL3XRtkP1WVbMxf7dtTdu in service spop Mar 19 14:40:06 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:3oL3XRtkP1WVbMxf7dtTdu Mar 19 14:40:06 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , search Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: tidal , search Mar 19 14:40:06 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , search Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: tidal , search Mar 19 14:40:06 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: mpd , search Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: spop , search Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: tidal , search Mar 19 14:40:06 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::volumioGetQueue Mar 19 14:40:06 volumio volumio[958]: info: CoreStateMachine::getQueue Mar 19 14:40:06 volumio volumio[958]: info: CorePlayQueue::getQueue Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::volumioAddQueueItems Mar 19 14:40:06 volumio volumio[958]: info: CoreStateMachine::addQueueItems Mar 19 14:40:06 volumio volumio[958]: info: CorePlayQueue::addQueueItems Mar 19 14:40:06 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:06 volumio volumio[958]: info: Adding Item to queue: spotify:track:1HNkqx9Ahdgi1Ixy2xkKkL Mar 19 14:40:06 volumio volumio[958]: info: Exploding uri spotify:track:1HNkqx9Ahdgi1Ixy2xkKkL in service spop Mar 19 14:40:06 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:1HNkqx9Ahdgi1Ixy2xkKkL Mar 19 14:40:06 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::volumioGetQueue Mar 19 14:40:06 volumio volumio[958]: info: CoreStateMachine::getQueue Mar 19 14:40:06 volumio volumio[958]: info: CorePlayQueue::getQueue Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::volumioAddQueueItems Mar 19 14:40:06 volumio volumio[958]: info: CoreStateMachine::addQueueItems Mar 19 14:40:06 volumio volumio[958]: info: CorePlayQueue::addQueueItems Mar 19 14:40:06 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:06 volumio volumio[958]: info: Adding Item to queue: spotify:track:5uCax9HTNlzGybIStD3vDh Mar 19 14:40:06 volumio volumio[958]: info: Exploding uri spotify:track:5uCax9HTNlzGybIStD3vDh in service spop Mar 19 14:40:06 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:5uCax9HTNlzGybIStD3vDh Mar 19 14:40:06 volumio volumio[958]: info: All cached search sources collected Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::volumioGetQueue Mar 19 14:40:06 volumio volumio[958]: info: CoreStateMachine::getQueue Mar 19 14:40:06 volumio volumio[958]: info: CorePlayQueue::getQueue Mar 19 14:40:06 volumio volumio[958]: info: CoreCommandRouter::volumioAddQueueItems Mar 19 14:40:06 volumio volumio[958]: info: CoreStateMachine::addQueueItems Mar 19 14:40:06 volumio volumio[958]: info: CorePlayQueue::addQueueItems Mar 19 14:40:06 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:06 volumio volumio[958]: info: Adding Item to queue: spotify:track:7wZUrN8oemZfsEd1CGkbXE Mar 19 14:40:06 volumio volumio[958]: info: Exploding uri spotify:track:7wZUrN8oemZfsEd1CGkbXE in service spop Mar 19 14:40:06 volumio volumio[958]: SPOTIFY: EXPLODING URI:spotify:track:7wZUrN8oemZfsEd1CGkbXE Mar 19 14:40:09 volumio volumio[958]: info: searchTIDALUri took 3467 milliseconds Mar 19 14:40:09 volumio volumio[958]: info: search took 3468 milliseconds Mar 19 14:40:09 volumio volumio[958]: info: All search sources collected, pushing search results Mar 19 14:40:09 volumio volumio[958]: info: CoreCommandRouter::volumioGetQueue Mar 19 14:40:09 volumio volumio[958]: info: CoreStateMachine::getQueue Mar 19 14:40:09 volumio volumio[958]: info: CorePlayQueue::getQueue Mar 19 14:40:09 volumio volumio[958]: info: CoreCommandRouter::volumioAddQueueItems Mar 19 14:40:09 volumio volumio[958]: info: CoreStateMachine::addQueueItems Mar 19 14:40:09 volumio volumio[958]: info: CorePlayQueue::addQueueItems Mar 19 14:40:09 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:09 volumio volumio[958]: info: Adding Item to queue: tidal://song/29583557 Mar 19 14:40:09 volumio volumio[958]: info: Exploding uri tidal://song/29583557 in service tidal Mar 19 14:40:09 volumio volumio[958]: info: searchTIDALUri took 4176 milliseconds Mar 19 14:40:09 volumio volumio[958]: info: search took 4177 milliseconds Mar 19 14:40:09 volumio volumio[958]: info: searchTIDALUri took 4200 milliseconds Mar 19 14:40:09 volumio volumio[958]: info: search took 4201 milliseconds Mar 19 14:40:10 volumio volumio[958]: info: searchTIDALUri took 4380 milliseconds Mar 19 14:40:10 volumio volumio[958]: info: search took 4381 milliseconds Mar 19 14:40:10 volumio volumio[958]: info: All search sources collected, pushing search results Mar 19 14:40:10 volumio volumio[958]: info: CoreCommandRouter::volumioGetQueue Mar 19 14:40:10 volumio volumio[958]: info: CoreStateMachine::getQueue Mar 19 14:40:10 volumio volumio[958]: info: CorePlayQueue::getQueue Mar 19 14:40:10 volumio volumio[958]: info: CoreCommandRouter::volumioAddQueueItems Mar 19 14:40:10 volumio volumio[958]: info: CoreStateMachine::addQueueItems Mar 19 14:40:10 volumio volumio[958]: info: CorePlayQueue::addQueueItems Mar 19 14:40:10 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:10 volumio volumio[958]: info: Adding Item to queue: tidal://song/2024977 Mar 19 14:40:10 volumio volumio[958]: info: Exploding uri tidal://song/2024977 in service tidal Mar 19 14:40:10 volumio volumio[958]: info: searchTIDALUri took 4423 milliseconds Mar 19 14:40:10 volumio volumio[958]: info: search took 4423 milliseconds Mar 19 14:40:10 volumio volumio[958]: info: searchTIDALUri took 4444 milliseconds Mar 19 14:40:10 volumio volumio[958]: info: search took 4444 milliseconds Mar 19 14:40:10 volumio volumio[958]: info: All search sources collected, pushing search results Mar 19 14:40:10 volumio volumio[958]: info: CoreCommandRouter::volumioGetQueue Mar 19 14:40:10 volumio volumio[958]: info: CoreStateMachine::getQueue Mar 19 14:40:10 volumio volumio[958]: info: CorePlayQueue::getQueue Mar 19 14:40:10 volumio volumio[958]: info: CoreCommandRouter::volumioAddQueueItems Mar 19 14:40:10 volumio volumio[958]: info: CoreStateMachine::addQueueItems Mar 19 14:40:10 volumio volumio[958]: info: CorePlayQueue::addQueueItems Mar 19 14:40:10 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:10 volumio volumio[958]: info: Adding Item to queue: tidal://song/1781573 Mar 19 14:40:10 volumio volumio[958]: info: Using cached record of: tidal://song/1781573 Mar 19 14:40:10 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue Mar 19 14:40:10 volumio volumio[958]: info: CorePlayQueue::saveQueue Mar 19 14:40:10 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Mar 19 14:40:10 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Mar 19 14:40:10 volumio volumio[958]: info: searchTIDALUri took 4531 milliseconds Mar 19 14:40:10 volumio volumio[958]: info: search took 4532 milliseconds Mar 19 14:40:11 volumio volumio[958]: info: searchTIDALUri took 5315 milliseconds Mar 19 14:40:11 volumio volumio[958]: info: search took 5316 milliseconds Mar 19 14:40:11 volumio volumio[958]: info: All search sources collected, pushing search results Mar 19 14:40:11 volumio volumio[958]: info: CoreCommandRouter::volumioGetQueue Mar 19 14:40:11 volumio volumio[958]: info: CoreStateMachine::getQueue Mar 19 14:40:11 volumio volumio[958]: info: CorePlayQueue::getQueue Mar 19 14:40:11 volumio volumio[958]: info: CoreCommandRouter::volumioAddQueueItems Mar 19 14:40:11 volumio volumio[958]: info: CoreStateMachine::addQueueItems Mar 19 14:40:11 volumio volumio[958]: info: CorePlayQueue::addQueueItems Mar 19 14:40:11 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:11 volumio volumio[958]: info: Adding Item to queue: tidal://song/21977343 Mar 19 14:40:11 volumio volumio[958]: info: Exploding uri tidal://song/21977343 in service tidal Mar 19 14:40:11 volumio volumio[958]: info: searchTIDALUri took 5437 milliseconds Mar 19 14:40:11 volumio volumio[958]: info: search took 5437 milliseconds Mar 19 14:40:11 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 19 14:40:11 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3oL3XRtkP1WVbMxf7dtTdu","service":"spop","name":"The One That Got Away","artist":"Katy Perry","album":"Teenage Dream: The Complete Confection","type":"song","duration":227,"albumart":"https://i.scdn.co/image/ab67616d0000b273937af329667311f4b2831616","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 19 14:40:11 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue Mar 19 14:40:11 volumio volumio[958]: info: CorePlayQueue::saveQueue Mar 19 14:40:11 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Mar 19 14:40:11 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Mar 19 14:40:11 volumio volumio[958]: info: searchTIDALUri took 5534 milliseconds Mar 19 14:40:11 volumio volumio[958]: info: search took 5535 milliseconds Mar 19 14:40:11 volumio volumio[958]: info: All search sources collected, pushing search results Mar 19 14:40:11 volumio volumio[958]: info: CoreCommandRouter::volumioGetQueue Mar 19 14:40:11 volumio volumio[958]: info: CoreStateMachine::getQueue Mar 19 14:40:11 volumio volumio[958]: info: CorePlayQueue::getQueue Mar 19 14:40:11 volumio volumio[958]: info: CoreCommandRouter::volumioAddQueueItems Mar 19 14:40:11 volumio volumio[958]: info: CoreStateMachine::addQueueItems Mar 19 14:40:11 volumio volumio[958]: info: CorePlayQueue::addQueueItems Mar 19 14:40:11 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:11 volumio volumio[958]: info: Adding Item to queue: tidal://song/9979811 Mar 19 14:40:11 volumio volumio[958]: info: Exploding uri tidal://song/9979811 in service tidal Mar 19 14:40:11 volumio volumio[958]: info: searchTIDALUri took 5714 milliseconds Mar 19 14:40:11 volumio volumio[958]: info: search took 5715 milliseconds Mar 19 14:40:11 volumio volumio[958]: info: All search sources collected, pushing search results Mar 19 14:40:11 volumio volumio[958]: info: CoreCommandRouter::volumioGetQueue Mar 19 14:40:11 volumio volumio[958]: info: CoreStateMachine::getQueue Mar 19 14:40:11 volumio volumio[958]: info: CorePlayQueue::getQueue Mar 19 14:40:11 volumio volumio[958]: info: CoreCommandRouter::volumioAddQueueItems Mar 19 14:40:11 volumio volumio[958]: info: CoreStateMachine::addQueueItems Mar 19 14:40:11 volumio volumio[958]: info: CorePlayQueue::addQueueItems Mar 19 14:40:11 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:11 volumio volumio[958]: info: Adding Item to queue: tidal://song/52885553 Mar 19 14:40:11 volumio volumio[958]: info: Exploding uri tidal://song/52885553 in service tidal Mar 19 14:40:11 volumio volumio[958]: info: searchTIDALUri took 5786 milliseconds Mar 19 14:40:11 volumio volumio[958]: info: search took 5787 milliseconds Mar 19 14:40:11 volumio volumio[958]: info: All search sources collected, pushing search results Mar 19 14:40:11 volumio volumio[958]: info: CoreCommandRouter::volumioGetQueue Mar 19 14:40:11 volumio volumio[958]: info: CoreStateMachine::getQueue Mar 19 14:40:11 volumio volumio[958]: info: CorePlayQueue::getQueue Mar 19 14:40:11 volumio volumio[958]: info: CoreCommandRouter::volumioAddQueueItems Mar 19 14:40:11 volumio volumio[958]: info: CoreStateMachine::addQueueItems Mar 19 14:40:11 volumio volumio[958]: info: CorePlayQueue::addQueueItems Mar 19 14:40:11 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:11 volumio volumio[958]: info: Adding Item to queue: tidal://song/5267743 Mar 19 14:40:11 volumio volumio[958]: info: Exploding uri tidal://song/5267743 in service tidal Mar 19 14:40:11 volumio volumio[958]: info: searchTIDALUri took 5141 milliseconds Mar 19 14:40:11 volumio volumio[958]: info: search took 5141 milliseconds Mar 19 14:40:11 volumio volumio[958]: info: searchTIDALUri took 5227 milliseconds Mar 19 14:40:11 volumio volumio[958]: info: search took 5228 milliseconds Mar 19 14:40:12 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1HNkqx9Ahdgi1Ixy2xkKkL","service":"spop","name":"Photograph","artist":"Ed Sheeran","album":"x (Deluxe Edition)","type":"song","duration":258,"albumart":"https://i.scdn.co/image/ab67616d0000b27313b3e37318a0c247b550bccd","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 19 14:40:12 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue Mar 19 14:40:12 volumio volumio[958]: info: CorePlayQueue::saveQueue Mar 19 14:40:12 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Mar 19 14:40:12 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Mar 19 14:40:12 volumio volumio[958]: info: searchTIDALUri took 5489 milliseconds Mar 19 14:40:12 volumio volumio[958]: info: search took 5489 milliseconds Mar 19 14:40:12 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5uCax9HTNlzGybIStD3vDh","service":"spop","name":"Say You Won't Let Go","artist":"James Arthur","album":"Back from the Edge","type":"song","duration":211,"albumart":"https://i.scdn.co/image/ab67616d0000b27320beb61f61fcbeb33b10a9ab","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 19 14:40:12 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue Mar 19 14:40:12 volumio volumio[958]: info: CorePlayQueue::saveQueue Mar 19 14:40:12 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Mar 19 14:40:12 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Mar 19 14:40:12 volumio volumio[958]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7wZUrN8oemZfsEd1CGkbXE","service":"spop","name":"Bleeding Love","artist":"Leona Lewis","album":"Spirit","type":"song","duration":262,"albumart":"https://i.scdn.co/image/ab67616d0000b27334fd9eb8cd48e518598aec55","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Mar 19 14:40:12 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue Mar 19 14:40:12 volumio volumio[958]: info: CorePlayQueue::saveQueue Mar 19 14:40:12 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Mar 19 14:40:12 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Mar 19 14:40:12 volumio volumio[958]: info: explodeTIDALUri took 2957 milliseconds Mar 19 14:40:12 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue Mar 19 14:40:12 volumio volumio[958]: info: CorePlayQueue::saveQueue Mar 19 14:40:12 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Mar 19 14:40:12 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Mar 19 14:40:12 volumio volumio[958]: info: explodeTIDALUri took 2651 milliseconds Mar 19 14:40:12 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue Mar 19 14:40:12 volumio volumio[958]: info: CorePlayQueue::saveQueue Mar 19 14:40:12 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Mar 19 14:40:12 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Mar 19 14:40:13 volumio volumio[958]: info: explodeTIDALUri took 1853 milliseconds Mar 19 14:40:13 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue Mar 19 14:40:13 volumio volumio[958]: info: CorePlayQueue::saveQueue Mar 19 14:40:13 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Mar 19 14:40:13 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Mar 19 14:40:14 volumio volumio[958]: info: explodeTIDALUri took 2704 milliseconds Mar 19 14:40:14 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue Mar 19 14:40:14 volumio volumio[958]: info: CorePlayQueue::saveQueue Mar 19 14:40:14 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Mar 19 14:40:14 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Mar 19 14:40:14 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 19 14:40:15 volumio volumio[958]: error: Search in plugin tidal timed out Mar 19 14:40:15 volumio volumio[958]: info: All search sources collected, pushing search results Mar 19 14:40:15 volumio volumio[958]: error: Search in plugin tidal timed out Mar 19 14:40:15 volumio volumio[958]: info: All search sources collected, pushing search results Mar 19 14:40:15 volumio volumio[958]: error: Search in plugin tidal timed out Mar 19 14:40:15 volumio volumio[958]: info: All search sources collected, pushing search results Mar 19 14:40:15 volumio volumio[958]: error: Search in plugin tidal timed out Mar 19 14:40:15 volumio volumio[958]: info: All search sources collected, pushing search results Mar 19 14:40:15 volumio volumio[958]: error: Search in plugin tidal timed out Mar 19 14:40:15 volumio volumio[958]: info: All search sources collected, pushing search results Mar 19 14:40:16 volumio volumio[958]: error: Search in plugin tidal timed out Mar 19 14:40:16 volumio volumio[958]: info: All search sources collected, pushing search results Mar 19 14:40:16 volumio volumio[958]: error: Search in plugin tidal timed out Mar 19 14:40:16 volumio volumio[958]: info: All search sources collected, pushing search results Mar 19 14:40:16 volumio volumio[958]: error: Search in plugin tidal timed out Mar 19 14:40:16 volumio volumio[958]: info: All search sources collected, pushing search results Mar 19 14:40:16 volumio volumio[958]: info: METAVOLUMIO: Infinity Playback added 11 Tracks to queue Mar 19 14:40:17 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 19 14:40:17 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 19 14:40:17 volumio volumio[958]: info: Discovery: Getting this device information Mar 19 14:40:17 volumio volumio[958]: info: CoreCommandRouter::volumioGetState Mar 19 14:40:17 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 19 14:40:17 volumio volumio[958]: info: explodeTIDALUri took 5661 milliseconds Mar 19 14:40:17 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue Mar 19 14:40:17 volumio volumio[958]: info: CorePlayQueue::saveQueue Mar 19 14:40:17 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Mar 19 14:40:17 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Mar 19 14:40:17 volumio volumio[958]: info: explodeTIDALUri took 5758 milliseconds Mar 19 14:40:17 volumio volumio[958]: info: CoreCommandRouter::volumioPushQueue Mar 19 14:40:17 volumio volumio[958]: info: CorePlayQueue::saveQueue Mar 19 14:40:17 volumio volumio[958]: info: CoreStateMachine::updateTrackBlock Mar 19 14:40:17 volumio volumio[958]: info: CorePlayQueue::getTrackBlock Mar 19 14:40:17 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 19 14:40:21 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:21 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:22 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:22 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:22 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:22 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:22 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:22 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:22 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 19 14:40:22 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35001 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46782 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35007 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46783 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35009 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46784 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35002 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46785 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35003 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46786 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35008 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46787 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35006 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46788 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35004 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46789 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35000 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46790 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35005 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46791 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38869 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38879 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38877 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38868 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38872 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38875 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38873 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38870 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38876 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38882 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38880 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38885 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38871 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38881 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38883 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38884 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38878 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38874 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@39759 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28724 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28725 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28727 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46898 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46899 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46900 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31365 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@29248 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46926 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@29197 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@29193 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@29198 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@29201 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@29205 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46928 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46934 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46935 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46936 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46943 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31295 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31298 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31287 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31292 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31294 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31285 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28795 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28787 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28791 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28792 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28788 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28794 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28786 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46945 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46946 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46950 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46951 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46952 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46953 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46954 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31244 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31613 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31610 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31606 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31616 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31612 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31605 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31611 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31607 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31614 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31603 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31608 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31604 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31609 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31615 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@47628 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@47629 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@47630 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@47631 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@47632 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@47633 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@47634 Mar 19 14:40:22 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35001 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46782 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35007 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46783 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35009 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46784 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35002 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46785 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35003 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46786 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35008 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46787 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35006 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46788 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35004 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46789 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35000 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46790 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35005 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46791 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38869 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38879 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38877 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38868 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38872 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38875 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38873 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38870 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38876 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38882 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38880 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38885 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38871 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38881 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38883 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38884 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38878 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@38874 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@39759 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28724 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28725 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28727 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46898 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46899 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46900 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31365 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@29248 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46926 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@29197 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@29193 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@29198 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@29201 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@29205 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46928 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46934 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46935 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46936 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46943 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31295 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31298 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31287 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31292 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31294 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31285 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28795 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28787 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28791 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28792 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28788 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28794 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@28786 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46945 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46946 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46950 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46951 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46952 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46953 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46954 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31244 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31613 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31610 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31606 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31616 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31612 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31605 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31611 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31607 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31614 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31603 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31608 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31604 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31609 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@31615 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@47628 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@47629 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@47630 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@47631 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@47632 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@47633 Mar 19 14:40:22 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@47634 Mar 19 14:40:22 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35001 in service upnp_browser Mar 19 14:40:22 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46782 in service upnp_browser Mar 19 14:40:22 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35007 in service upnp_browser Mar 19 14:40:23 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46783 in service upnp_browser Mar 19 14:40:23 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35009 in service upnp_browser Mar 19 14:40:23 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46784 in service upnp_browser Mar 19 14:40:23 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35002 in service upnp_browser Mar 19 14:40:23 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46785 in service upnp_browser Mar 19 14:40:23 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@35003 in service upnp_browser Mar 19 14:40:23 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@23$@46786 in service upnp_browser Mar 19 14:40:23 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:28 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 19 14:40:29 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:29 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:35 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: Cannot compose Albumart path Mar 19 14:40:35 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38869 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38879 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38877 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38868 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38872 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38875 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38873 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38870 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38876 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38882 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38880 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38885 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38871 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38881 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38883 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38884 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38878 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38874 Mar 19 14:40:35 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38867 Mar 19 14:40:35 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38869 in service upnp_browser Mar 19 14:40:35 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38879 in service upnp_browser Mar 19 14:40:35 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38877 in service upnp_browser Mar 19 14:40:36 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38868 in service upnp_browser Mar 19 14:40:36 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38872 in service upnp_browser Mar 19 14:40:36 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38875 in service upnp_browser Mar 19 14:40:36 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38873 in service upnp_browser Mar 19 14:40:36 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38870 in service upnp_browser Mar 19 14:40:36 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38876 in service upnp_browser Mar 19 14:40:36 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38882 in service upnp_browser Mar 19 14:40:36 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38880 in service upnp_browser Mar 19 14:40:36 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38885 in service upnp_browser Mar 19 14:40:36 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38871 in service upnp_browser Mar 19 14:40:36 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38881 in service upnp_browser Mar 19 14:40:36 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38883 in service upnp_browser Mar 19 14:40:36 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38884 in service upnp_browser Mar 19 14:40:36 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38878 in service upnp_browser Mar 19 14:40:36 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38874 in service upnp_browser Mar 19 14:40:36 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38867 in service upnp_browser Mar 19 14:40:44 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 19 14:40:44 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 19 14:40:44 volumio volumio[958]: info: Discovery: Getting this device information Mar 19 14:40:44 volumio volumio[958]: info: CoreCommandRouter::volumioGetState Mar 19 14:40:44 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 19 14:40:55 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 19 14:40:56 volumio volumio[958]: info: Preload queue cleared Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38940 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38939 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38938 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38935 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38942 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38949 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38941 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38948 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38951 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38952 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38947 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38944 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38943 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38946 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38934 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38945 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38937 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38953 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38950 Mar 19 14:40:56 volumio volumio[958]: info: Preloading song: upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38936 Mar 19 14:40:56 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38940 in service upnp_browser Mar 19 14:40:56 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38939 in service upnp_browser Mar 19 14:40:56 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38938 in service upnp_browser Mar 19 14:40:56 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38935 in service upnp_browser Mar 19 14:40:56 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38942 in service upnp_browser Mar 19 14:40:56 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38949 in service upnp_browser Mar 19 14:40:56 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38941 in service upnp_browser Mar 19 14:40:56 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38948 in service upnp_browser Mar 19 14:40:56 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38951 in service upnp_browser Mar 19 14:40:56 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38952 in service upnp_browser Mar 19 14:40:56 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38947 in service upnp_browser Mar 19 14:40:56 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38944 in service upnp_browser Mar 19 14:40:56 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38943 in service upnp_browser Mar 19 14:40:56 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38946 in service upnp_browser Mar 19 14:40:56 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38934 in service upnp_browser Mar 19 14:40:57 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38945 in service upnp_browser Mar 19 14:40:57 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38937 in service upnp_browser Mar 19 14:40:57 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38953 in service upnp_browser Mar 19 14:40:57 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38950 in service upnp_browser Mar 19 14:40:57 volumio volumio[958]: info: Exploding uri upnp/http://192.168.100.13:50001/ContentDirectory/control@22$@38936 in service upnp_browser Mar 19 14:40:57 volumio go-librespot[32291]: time="2025-03-19T14:40:57Z" level=fatal msg="failed running with username and spotify token" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 104.199.65.124:4070: connect: connection timed out" Mar 19 14:40:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Mar 19 14:40:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Mar 19 14:40:57 volumio volumio[958]: (node:958) UnhandledPromiseRejectionWarning: Error: socket hang up Mar 19 14:40:57 volumio volumio[958]: at connResetException (internal/errors.js:607:14) Mar 19 14:40:57 volumio volumio[958]: at Socket.socketOnEnd (_http_client.js:493:23) Mar 19 14:40:57 volumio volumio[958]: at Socket.emit (events.js:327:22) Mar 19 14:40:57 volumio volumio[958]: at endReadableNT (internal/streams/readable.js:1327:12) Mar 19 14:40:57 volumio volumio[958]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Mar 19 14:40:57 volumio volumio[958]: (node:958) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 93) Mar 19 14:40:57 volumio volumio[958]: info: Connection to go-librespot Websocket closed Mar 19 14:41:00 volumio volumio[958]: info: Initializing connection to go-librespot Websocket Mar 19 14:41:00 volumio systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Mar 19 14:41:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 93. Mar 19 14:41:00 volumio systemd[1]: Stopped go-librespot Daemon. Mar 19 14:41:00 volumio volumio[958]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Mar 19 14:41:00 volumio systemd[1]: Started go-librespot Daemon. Mar 19 14:41:00 volumio go-librespot[32621]: Librespot-go daemon starting... Mar 19 14:41:00 volumio go-librespot[32621]: time="2025-03-19T14:41:00Z" level=info msg="generated new device id: 6a68c6a1e1b3e87a677b70f00582174f145fa566" Mar 19 14:41:00 volumio go-librespot[32621]: time="2025-03-19T14:41:00Z" level=debug msg="stored credentials found for y2mzdf5b7q8ydzc3btfrd2r7r" Mar 19 14:41:00 volumio go-librespot[32621]: time="2025-03-19T14:41:00Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Mar 19 14:41:00 volumio go-librespot[32621]: time="2025-03-19T14:41:00Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Mar 19 14:41:00 volumio go-librespot[32621]: time="2025-03-19T14:41:00Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Mar 19 14:41:00 volumio go-librespot[32621]: time="2025-03-19T14:41:00Z" level=debug msg="zeroconf server listening on port 41959" Mar 19 14:41:00 volumio go-librespot[32621]: time="2025-03-19T14:41:00Z" level=debug msg="obtained new client token: AABxxPVKqSU9aAlYwscSRELbVYjHlS+v3ci4kr3X0+8YUf+Po6nhETSbf9vQjaQOCQxCCs0MDuY73Q7svjDdTzpBB1GrgO7jvBrMr4yq8gq6rvDdmTuaeD5+IMOQJjQCPV0z12lfAOtUJBzJbnHTcI5D7/D7GyMPC26J5sPh0vpQxvAOX9LF7w3W9bE6bPBaysDoE2nmLOJAtFHuNqUwTMtmg1dIoK/GVuHd4HGewxV9OEhej5Cpo4Op9w==" Mar 19 14:41:03 volumio volumio[958]: info: Initializing connection to go-librespot Websocket Mar 19 14:41:03 volumio go-librespot[32621]: time="2025-03-19T14:41:03Z" level=debug msg="new websocket client" Mar 19 14:41:03 volumio volumio[958]: info: Connection to go-librespot Websocket established Mar 19 14:41:04 volumio volumio[958]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Mar 19 14:41:04 volumio volumio[958]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 19 14:41:04 volumio volumio[958]: TypeError: Cannot read property 'length' of undefined Mar 19 14:41:04 volumio volumio[958]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Mar 19 14:41:04 volumio volumio[958]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Mar 19 14:41:04 volumio volumio[958]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Mar 19 14:41:04 volumio volumio[958]: at Parser.emit (events.js:315:20) Mar 19 14:41:04 volumio volumio[958]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Mar 19 14:41:04 volumio volumio[958]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Mar 19 14:41:04 volumio volumio[958]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Mar 19 14:41:04 volumio volumio[958]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Mar 19 14:41:04 volumio volumio[958]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Mar 19 14:41:04 volumio volumio[958]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Mar 19 14:41:04 volumio volumio[958]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Mar 19 14:41:04 volumio volumio[958]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Mar 19 14:41:04 volumio volumio[958]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Mar 19 14:41:04 volumio volumio[958]: at IncomingMessage.emit (events.js:327:22) Mar 19 14:41:04 volumio volumio[958]: at endReadableNT (internal/streams/readable.js:1327:12) Mar 19 14:41:04 volumio volumio[958]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Mar 19 14:41:04 volumio volumio[958]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 19 14:41:04 volumio sudo[32643]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-19 14:40 Mar 19 14:41:04 volumio sudo[32643]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 11:42:54 AM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4049a67f1c09d4a94e033ba35a80a144"