Jan 12 11:13:05 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:13:07 volumio volumio[974]: info: Executing endpoint metavolumio Jan 12 11:13:07 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 11:13:07 volumio volumio[974]: info: Executing endpoint metavolumio Jan 12 11:13:07 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 11:13:07 volumio volumio[974]: info: Executing endpoint metavolumio Jan 12 11:13:07 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 11:13:15 volumio volumio[974]: Searching plugin music_service/tidal Jan 12 11:13:15 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: tidal , search Jan 12 11:13:16 volumio volumio[974]: info: searchTIDALUri took 591 milliseconds Jan 12 11:13:16 volumio volumio[974]: info: search took 595 milliseconds Jan 12 11:13:16 volumio volumio[974]: info: All search sources collected, pushing search results Jan 12 11:13:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Jan 12 11:13:20 volumio volumio[974]: info: browseTIDALUri took 1510 milliseconds Jan 12 11:13:20 volumio volumio[974]: info: Preload queue cleared Jan 12 11:13:20 volumio volumio[974]: info: Preload queue cleared Jan 12 11:13:20 volumio volumio[974]: info: Preload queue cleared Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/21651821 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/21651822 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/634657 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/21651817 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/77616490 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/2531983 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/77640001 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/2531987 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/16806750 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/27514143 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/21651824 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/21651819 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/21651820 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/34852104 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/634665 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/2531981 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/98491599 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/336171224 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/4021139 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/16806753 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/355473676 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/77616489 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/21651818 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/2531978 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/634662 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/27514142 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/3800722 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/577148 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/3800721 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/98491602 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/98491603 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/27514141 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/3800713 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/16806751 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/634668 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/98491600 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/2531982 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/98491598 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/77616487 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/634663 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/34852101 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/622284 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/98491601 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/16806754 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/355473677 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/77616481 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/34852100 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/577156 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/3800723 Jan 12 11:13:20 volumio volumio[974]: info: Preloading song: tidal://song/3951736 Jan 12 11:13:20 volumio volumio[974]: info: Exploding uri tidal://song/21651821 in service tidal Jan 12 11:13:20 volumio volumio[974]: info: Exploding uri tidal://song/21651822 in service tidal Jan 12 11:13:20 volumio volumio[974]: info: Exploding uri tidal://song/634657 in service tidal Jan 12 11:13:20 volumio volumio[974]: info: Exploding uri tidal://song/21651817 in service tidal Jan 12 11:13:20 volumio volumio[974]: info: explodeTIDALUri took 176 milliseconds Jan 12 11:13:20 volumio volumio[974]: info: Exploding uri tidal://song/77616490 in service tidal Jan 12 11:13:20 volumio volumio[974]: info: Exploding uri tidal://song/2531983 in service tidal Jan 12 11:13:20 volumio volumio[974]: info: Exploding uri tidal://song/77640001 in service tidal Jan 12 11:13:20 volumio volumio[974]: info: Exploding uri tidal://song/2531987 in service tidal Jan 12 11:13:20 volumio volumio[974]: info: explodeTIDALUri took 233 milliseconds Jan 12 11:13:20 volumio volumio[974]: info: Exploding uri tidal://song/16806750 in service tidal Jan 12 11:13:20 volumio volumio[974]: info: explodeTIDALUri took 401 milliseconds Jan 12 11:13:20 volumio volumio[974]: info: Exploding uri tidal://song/27514143 in service tidal Jan 12 11:13:20 volumio volumio[974]: info: Exploding uri tidal://song/21651824 in service tidal Jan 12 11:13:20 volumio volumio[974]: info: Exploding uri tidal://song/21651819 in service tidal Jan 12 11:13:20 volumio volumio[974]: info: Exploding uri tidal://song/21651820 in service tidal Jan 12 11:13:20 volumio volumio[974]: info: explodeTIDALUri took 477 milliseconds Jan 12 11:13:20 volumio volumio[974]: info: explodeTIDALUri took 189 milliseconds Jan 12 11:13:20 volumio volumio[974]: info: explodeTIDALUri took 181 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/34852104 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/634665 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 441 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/2531981 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 476 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 682 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/98491599 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 193 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/336171224 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 180 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/4021139 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 303 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 573 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/16806753 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 167 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/355473676 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 176 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/77616489 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 166 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/21651818 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/2531978 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 452 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 168 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 223 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/634662 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 169 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/27514142 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 165 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 769 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/3800722 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 564 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 171 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/577148 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 165 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/3800721 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 164 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/98491602 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 170 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Executing endpoint getSimilarArtists Jan 12 11:13:21 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/98491603 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: Executing endpoint getSimilarArtists Jan 12 11:13:21 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 199 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/27514141 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 168 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/3800713 in service tidal Jan 12 11:13:21 volumio volumio[974]: info: explodeTIDALUri took 167 milliseconds Jan 12 11:13:21 volumio volumio[974]: info: Executing endpoint metavolumio Jan 12 11:13:21 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 11:13:21 volumio volumio[974]: info: Executing endpoint metavolumio Jan 12 11:13:21 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 11:13:21 volumio volumio[974]: info: Exploding uri tidal://song/16806751 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 195 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: Exploding uri tidal://song/634668 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 165 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: Exploding uri tidal://song/98491600 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 165 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: Exploding uri tidal://song/2531982 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: Exploding uri tidal://song/98491598 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 187 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 169 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: Exploding uri tidal://song/77616487 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 164 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: Exploding uri tidal://song/634663 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 185 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: Exploding uri tidal://song/34852101 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 166 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: Exploding uri tidal://song/622284 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 169 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: Exploding uri tidal://song/98491601 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 170 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: Exploding uri tidal://song/16806754 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 165 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: Exploding uri tidal://song/355473677 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 176 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: Exploding uri tidal://song/77616481 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 168 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: Exploding uri tidal://song/34852100 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 174 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: Exploding uri tidal://song/577156 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 170 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: Exploding uri tidal://song/3800723 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 185 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: Exploding uri tidal://song/3951736 in service tidal Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 166 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 191 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 168 milliseconds Jan 12 11:13:22 volumio volumio[974]: info: explodeTIDALUri took 166 milliseconds Jan 12 11:13:41 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Jan 12 11:13:41 volumio volumio[974]: info: browseTIDALUri took 498 milliseconds Jan 12 11:13:42 volumio volumio[974]: info: Preload queue cleared Jan 12 11:13:42 volumio volumio[974]: info: Preloading song: tidal://song/42832135 Jan 12 11:13:42 volumio volumio[974]: info: Preloading song: tidal://song/42832136 Jan 12 11:13:42 volumio volumio[974]: info: Preloading song: tidal://song/42832137 Jan 12 11:13:42 volumio volumio[974]: info: Preloading song: tidal://song/42832138 Jan 12 11:13:42 volumio volumio[974]: info: Preloading song: tidal://song/42832139 Jan 12 11:13:42 volumio volumio[974]: info: Preloading song: tidal://song/42832142 Jan 12 11:13:42 volumio volumio[974]: info: Preloading song: tidal://song/42832147 Jan 12 11:13:42 volumio volumio[974]: info: Preloading song: tidal://song/42832148 Jan 12 11:13:42 volumio volumio[974]: info: Preloading song: tidal://song/42832149 Jan 12 11:13:42 volumio volumio[974]: info: Preloading song: tidal://song/42832150 Jan 12 11:13:42 volumio volumio[974]: info: Preloading song: tidal://song/42832151 Jan 12 11:13:42 volumio volumio[974]: info: Preloading song: tidal://song/42832152 Jan 12 11:13:42 volumio volumio[974]: info: Preloading song: tidal://song/42832153 Jan 12 11:13:42 volumio volumio[974]: info: Preloading song: tidal://song/42832154 Jan 12 11:13:42 volumio volumio[974]: info: Preloading song: tidal://song/42832155 Jan 12 11:13:42 volumio volumio[974]: info: Exploding uri tidal://song/42832135 in service tidal Jan 12 11:13:42 volumio volumio[974]: info: Exploding uri tidal://song/42832136 in service tidal Jan 12 11:13:42 volumio volumio[974]: info: Exploding uri tidal://song/42832137 in service tidal Jan 12 11:13:42 volumio volumio[974]: info: Exploding uri tidal://song/42832138 in service tidal Jan 12 11:13:42 volumio volumio[974]: info: explodeTIDALUri took 185 milliseconds Jan 12 11:13:42 volumio volumio[974]: info: Exploding uri tidal://song/42832139 in service tidal Jan 12 11:13:42 volumio volumio[974]: info: Exploding uri tidal://song/42832142 in service tidal Jan 12 11:13:42 volumio volumio[974]: info: Exploding uri tidal://song/42832147 in service tidal Jan 12 11:13:42 volumio volumio[974]: info: Exploding uri tidal://song/42832148 in service tidal Jan 12 11:13:42 volumio volumio[974]: info: Exploding uri tidal://song/42832149 in service tidal Jan 12 11:13:42 volumio volumio[974]: info: explodeTIDALUri took 234 milliseconds Jan 12 11:13:42 volumio volumio[974]: info: Exploding uri tidal://song/42832150 in service tidal Jan 12 11:13:42 volumio volumio[974]: info: explodeTIDALUri took 398 milliseconds Jan 12 11:13:42 volumio volumio[974]: info: Exploding uri tidal://song/42832151 in service tidal Jan 12 11:13:42 volumio volumio[974]: info: Exploding uri tidal://song/42832152 in service tidal Jan 12 11:13:42 volumio volumio[974]: info: Exploding uri tidal://song/42832153 in service tidal Jan 12 11:13:42 volumio volumio[974]: info: explodeTIDALUri took 664 milliseconds Jan 12 11:13:42 volumio volumio[974]: info: explodeTIDALUri took 569 milliseconds Jan 12 11:13:42 volumio volumio[974]: info: explodeTIDALUri took 301 milliseconds Jan 12 11:13:42 volumio volumio[974]: info: Exploding uri tidal://song/42832154 in service tidal Jan 12 11:13:42 volumio volumio[974]: info: Exploding uri tidal://song/42832155 in service tidal Jan 12 11:13:42 volumio volumio[974]: info: explodeTIDALUri took 243 milliseconds Jan 12 11:13:42 volumio volumio[974]: info: explodeTIDALUri took 435 milliseconds Jan 12 11:13:42 volumio volumio[974]: info: explodeTIDALUri took 503 milliseconds Jan 12 11:13:42 volumio volumio[974]: info: explodeTIDALUri took 247 milliseconds Jan 12 11:13:42 volumio volumio[974]: info: explodeTIDALUri took 469 milliseconds Jan 12 11:13:43 volumio volumio[974]: info: explodeTIDALUri took 254 milliseconds Jan 12 11:13:43 volumio volumio[974]: info: explodeTIDALUri took 181 milliseconds Jan 12 11:13:43 volumio volumio[974]: info: explodeTIDALUri took 183 milliseconds Jan 12 11:13:43 volumio volumio[974]: info: Executing endpoint metavolumio Jan 12 11:13:43 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 11:13:43 volumio volumio[974]: info: Executing endpoint getSimilarAlbums Jan 12 11:13:43 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Jan 12 11:13:43 volumio volumio[974]: info: Executing endpoint getSimilarAlbums Jan 12 11:13:43 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Jan 12 11:13:43 volumio volumio[974]: info: Executing endpoint metavolumio Jan 12 11:13:43 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 11:13:43 volumio volumio[974]: info: Executing endpoint metavolumio Jan 12 11:13:43 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 11:13:43 volumio volumio[974]: info: Executing endpoint metavolumio Jan 12 11:13:43 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 12 11:13:43 volumio volumio[974]: info: explodeTIDALUri took 666 milliseconds Jan 12 11:14:03 volumio volumio[974]: info: Preload queue cleared Jan 12 11:14:03 volumio volumio[974]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::ClearQueue Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::stop Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::serviceStop Jan 12 11:14:03 volumio volumio[974]: info: Received STOP, but no service to execute it Jan 12 11:14:03 volumio volumio[974]: info: CorePlayQueue::clearPlayQueue Jan 12 11:14:03 volumio volumio[974]: info: CorePlayQueue::saveQueue Jan 12 11:14:03 volumio volumio[974]: info: CoreCommandRouter::volumioPushQueue Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::addQueueItems Jan 12 11:14:03 volumio volumio[974]: info: CorePlayQueue::addQueueItems Jan 12 11:14:03 volumio volumio[974]: info: Preload queue cleared Jan 12 11:14:03 volumio volumio[974]: info: Adding Item to queue: tidal://song/42832135 Jan 12 11:14:03 volumio volumio[974]: info: Using cached record of: tidal://song/42832135 Jan 12 11:14:03 volumio volumio[974]: info: CoreCommandRouter::volumioPushQueue Jan 12 11:14:03 volumio volumio[974]: info: CorePlayQueue::saveQueue Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::updateTrackBlock Jan 12 11:14:03 volumio volumio[974]: info: CorePlayQueue::getTrackBlock Jan 12 11:14:03 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:14:03 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Jan 12 11:14:03 volumio volumio[974]: info: CoreCommandRouter::volumioPlay Jan 12 11:14:03 volumio volumio[974]: verbose: UNSET VOLATILE: Service: undefined Jan 12 11:14:03 volumio volumio[974]: ------------------------------------ BT MESSAGE: [FUNC] detachBluetooth Jan 12 11:14:03 volumio volumio[974]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput Jan 12 11:14:03 volumio volumio[974]: ------------------------------------ BT MESSAGE: [dbus-next] Disabling Bluetooth Audio Output Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::play index 0 Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::addQueueItems Jan 12 11:14:03 volumio volumio[974]: info: CorePlayQueue::addQueueItems Jan 12 11:14:03 volumio volumio[974]: info: Preload queue cleared Jan 12 11:14:03 volumio volumio[974]: info: Adding Item to queue: tidal://song/42832136 Jan 12 11:14:03 volumio volumio[974]: info: Using cached record of: tidal://song/42832136 Jan 12 11:14:03 volumio volumio[974]: info: Adding Item to queue: tidal://song/42832137 Jan 12 11:14:03 volumio volumio[974]: info: Using cached record of: tidal://song/42832137 Jan 12 11:14:03 volumio volumio[974]: info: Adding Item to queue: tidal://song/42832138 Jan 12 11:14:03 volumio volumio[974]: info: Using cached record of: tidal://song/42832138 Jan 12 11:14:03 volumio volumio[974]: info: Adding Item to queue: tidal://song/42832139 Jan 12 11:14:03 volumio volumio[974]: info: Using cached record of: tidal://song/42832139 Jan 12 11:14:03 volumio volumio[974]: info: Adding Item to queue: tidal://song/42832142 Jan 12 11:14:03 volumio volumio[974]: info: Using cached record of: tidal://song/42832142 Jan 12 11:14:03 volumio volumio[974]: info: Adding Item to queue: tidal://song/42832147 Jan 12 11:14:03 volumio volumio[974]: info: Using cached record of: tidal://song/42832147 Jan 12 11:14:03 volumio volumio[974]: info: Adding Item to queue: tidal://song/42832148 Jan 12 11:14:03 volumio volumio[974]: info: Using cached record of: tidal://song/42832148 Jan 12 11:14:03 volumio volumio[974]: info: Adding Item to queue: tidal://song/42832149 Jan 12 11:14:03 volumio volumio[974]: info: Using cached record of: tidal://song/42832149 Jan 12 11:14:03 volumio volumio[974]: info: Adding Item to queue: tidal://song/42832150 Jan 12 11:14:03 volumio volumio[974]: info: Using cached record of: tidal://song/42832150 Jan 12 11:14:03 volumio volumio[974]: info: Adding Item to queue: tidal://song/42832151 Jan 12 11:14:03 volumio volumio[974]: info: Using cached record of: tidal://song/42832151 Jan 12 11:14:03 volumio volumio[974]: info: Adding Item to queue: tidal://song/42832152 Jan 12 11:14:03 volumio volumio[974]: info: Using cached record of: tidal://song/42832152 Jan 12 11:14:03 volumio volumio[974]: info: Adding Item to queue: tidal://song/42832153 Jan 12 11:14:03 volumio volumio[974]: info: Using cached record of: tidal://song/42832153 Jan 12 11:14:03 volumio volumio[974]: info: Adding Item to queue: tidal://song/42832154 Jan 12 11:14:03 volumio volumio[974]: info: Using cached record of: tidal://song/42832154 Jan 12 11:14:03 volumio volumio[974]: info: Adding Item to queue: tidal://song/42832155 Jan 12 11:14:03 volumio volumio[974]: info: Using cached record of: tidal://song/42832155 Jan 12 11:14:03 volumio volumio[974]: ------------------------------------ BT MESSAGE: Bluetooth audio output disabled. Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::stop Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 11:14:03 volumio volumio[974]: info: CoreCommandRouter::volumioPushQueue Jan 12 11:14:03 volumio volumio[974]: info: CorePlayQueue::saveQueue Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::resetVolumioState Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::getcurrentVolume Jan 12 11:14:03 volumio volumio[974]: info: CoreCommandRouter::volumioRetrievevolume Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::play index undefined Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::updateTrackBlock Jan 12 11:14:03 volumio volumio[974]: info: CorePlayQueue::getTrackBlock Jan 12 11:14:03 volumio volumio[974]: info: CoreCommandRouter::volumioStop Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::stop Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 12 11:14:03 volumio volumio[974]: info: CorePlayQueue::getTrack 0 Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::startPlaybackTimer Jan 12 11:14:03 volumio volumio[974]: info: CorePlayQueue::getTrack 0 Jan 12 11:14:03 volumio volumio[974]: info: [1768212843478] ControllerTidal::clearAddPlayTrack Jan 12 11:14:03 volumio volumio[974]: info: Getting stream with soundQuality LOSSLESS Jan 12 11:14:03 volumio volumio[974]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number '5'. Jan 12 11:14:03 volumio volumio[974]: info: VolumeController:: Volume=undefined Mute =false Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::pushState Jan 12 11:14:03 volumio volumio[974]: info: CorePlayQueue::getTrack 0 Jan 12 11:14:03 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 11:14:03 volumio volumio[974]: info: CoreCommandRouter::volumioPushState Jan 12 11:14:03 volumio volumio[974]: info: MRS: Pushing multiroomSync output update for this device Jan 12 11:14:03 volumio volumio[974]: info: MRS: Pushing multiroomSync output Jan 12 11:14:03 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:14:03 volumio volumio[974]: info: CorePlayQueue::getTrack 0 Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::updateTrackBlock Jan 12 11:14:03 volumio volumio[974]: info: CorePlayQueue::getTrackBlock Jan 12 11:14:03 volumio volumio[974]: info: CoreCommandRouter::volumioRetrievevolume Jan 12 11:14:03 volumio volumio[974]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number '5'. Jan 12 11:14:03 volumio volumio[974]: info: VolumeController:: Volume=undefined Mute =false Jan 12 11:14:03 volumio volumio[974]: info: CoreStateMachine::pushState Jan 12 11:14:03 volumio volumio[974]: info: CorePlayQueue::getTrack 0 Jan 12 11:14:03 volumio volumio[974]: info: CoreCommandRouter::volumioPushState Jan 12 11:14:03 volumio volumio[974]: info: MRS: Pushing multiroomSync output update for this device Jan 12 11:14:03 volumio volumio[974]: info: MRS: Pushing multiroomSync output Jan 12 11:14:03 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:14:03 volumio volumio[974]: info: CorePlayQueue::getTrack 0 Jan 12 11:14:03 volumio volumio[974]: info: getStreamUrl took 506 milliseconds Jan 12 11:14:03 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand stop Jan 12 11:14:03 volumio volumio[974]: info: sendMpdCommand stop took 5 milliseconds Jan 12 11:14:03 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand clear Jan 12 11:14:04 volumio volumio[974]: info: Jan 12 11:14:04 volumio volumio[974]: ---------------------------- MPD announces system playlist update Jan 12 11:14:04 volumio volumio[974]: info: Ignoring MPD Status Update Jan 12 11:14:04 volumio volumio[974]: info: sendMpdCommand clear took 6 milliseconds Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicyZjI3YjJmNTA3ZjA2Y2I0MzJhYjJmNmEwYzM2MDAwMF82MS5tcDQ/0.flac?token=1768216443~MjgxYWQ4MWU3YTc1YzRmYzRkZWJlMTQ0M2Y0NTQwYjQ5NWJiMWJhNg==" Jan 12 11:14:04 volumio volumio[974]: info: Jan 12 11:14:04 volumio volumio[974]: ---------------------------- MPD announces system playlist update Jan 12 11:14:04 volumio volumio[974]: info: Ignoring MPD Status Update Jan 12 11:14:04 volumio volumio[974]: error: updateQueue error: null Jan 12 11:14:04 volumio volumio[974]: info: Jan 12 11:14:04 volumio volumio[974]: ---------------------------- MPD announces system playlist update Jan 12 11:14:04 volumio volumio[974]: info: Ignoring MPD Status Update Jan 12 11:14:04 volumio volumio[974]: info: ------------------------------ 18ms Jan 12 11:14:04 volumio volumio[974]: info: sendMpdCommand add "http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicyZjI3YjJmNTA3ZjA2Y2I0MzJhYjJmNmEwYzM2MDAwMF82MS5tcDQ/0.flac?token=1768216443~MjgxYWQ4MWU3YTc1YzRmYzRkZWJlMTQ0M2Y0NTQwYjQ5NWJiMWJhNg==" took 14 milliseconds Jan 12 11:14:04 volumio volumio[974]: info: ------------------------------ 12ms Jan 12 11:14:04 volumio volumio[974]: info: CoreStateMachine::setConsumeUpdateService mpd Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand play Jan 12 11:14:04 volumio volumio[974]: info: Jan 12 11:14:04 volumio volumio[974]: ---------------------------- MPD announces system playlist update Jan 12 11:14:04 volumio volumio[974]: info: Ignoring MPD Status Update Jan 12 11:14:04 volumio volumio[974]: info: ------------------------------ 15ms Jan 12 11:14:04 volumio volumio[974]: info: sendMpdCommand play took 8 milliseconds Jan 12 11:14:04 volumio volumio[974]: info: ------------------------------ 6ms Jan 12 11:14:04 volumio volumio[974]: info: Jan 12 11:14:04 volumio volumio[974]: ---------------------------- MPD announces state update: player Jan 12 11:14:04 volumio volumio[974]: info: ControllerMpd::getState Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status Jan 12 11:14:04 volumio volumio[974]: info: Jan 12 11:14:04 volumio volumio[974]: ---------------------------- MPD announces state update: player Jan 12 11:14:04 volumio volumio[974]: info: ControllerMpd::getState Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand clearerror Jan 12 11:14:04 volumio volumio[974]: info: sendMpdCommand status took 23 milliseconds Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::parseState Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 11:14:04 volumio volumio[974]: info: Jan 12 11:14:04 volumio volumio[974]: ---------------------------- MPD announces state update: player Jan 12 11:14:04 volumio volumio[974]: info: ControllerMpd::getState Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status Jan 12 11:14:04 volumio volumio[974]: info: Jan 12 11:14:04 volumio volumio[974]: ---------------------------- MPD announces state update: player Jan 12 11:14:04 volumio volumio[974]: info: ControllerMpd::getState Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand status Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand clearerror Jan 12 11:14:04 volumio volumio[974]: info: sendMpdCommand status took 52 milliseconds Jan 12 11:14:04 volumio volumio[974]: info: sendMpdCommand clearerror took 35 milliseconds Jan 12 11:14:04 volumio volumio[974]: info: sendMpdCommand playlistinfo took 29 milliseconds Jan 12 11:14:04 volumio volumio[974]: info: sendMpdCommand status took 23 milliseconds Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::parseState Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::parseTrackInfo Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::parseState Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 11:14:04 volumio volumio[974]: info: ControllerMpd::pushState Jan 12 11:14:04 volumio volumio[974]: info: CoreCommandRouter::servicePushState Jan 12 11:14:04 volumio volumio[974]: info: CorePlayQueue::getTrack 0 Jan 12 11:14:04 volumio volumio[974]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":400,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1768216443~MjgxYWQ4MWU3YTc1YzRmYzRkZWJlMTQ0M2Y0NTQwYjQ5NWJiMWJhNg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicyZjI3YjJmNTA3ZjA2Y2I0MzJhYjJmNmEwYzM2MDAwMF82MS5tcDQ/0.flac?token=1768216443~MjgxYWQ4MWU3YTc1YzRmYzRkZWJlMTQ0M2Y0NTQwYjQ5NWJiMWJhNg==","trackType":"tidal"} Jan 12 11:14:04 volumio volumio[974]: verbose: CURRENT POSITION 0 Jan 12 11:14:04 volumio volumio[974]: info: CoreStateMachine::syncState stateService pause Jan 12 11:14:04 volumio volumio[974]: info: CoreStateMachine::syncState currentStatus stop Jan 12 11:14:04 volumio volumio[974]: info: CoreStateMachine::pushState Jan 12 11:14:04 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 11:14:04 volumio volumio[974]: info: CoreCommandRouter::volumioPushState Jan 12 11:14:04 volumio volumio[974]: info: MRS: Pushing multiroomSync output update for this device Jan 12 11:14:04 volumio volumio[974]: info: MRS: Pushing multiroomSync output Jan 12 11:14:04 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:14:04 volumio volumio[974]: info: ------------------------------ 175ms Jan 12 11:14:04 volumio volumio[974]: info: sendMpdCommand status took 172 milliseconds Jan 12 11:14:04 volumio volumio[974]: info: sendMpdCommand clearerror took 161 milliseconds Jan 12 11:14:04 volumio volumio[974]: info: sendMpdCommand playlistinfo took 152 milliseconds Jan 12 11:14:04 volumio volumio[974]: info: sendMpdCommand playlistinfo took 146 milliseconds Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::parseState Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::parseTrackInfo Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::parseTrackInfo Jan 12 11:14:04 volumio volumio[974]: info: ControllerMpd::pushState Jan 12 11:14:04 volumio volumio[974]: info: CoreCommandRouter::servicePushState Jan 12 11:14:04 volumio volumio[974]: info: CorePlayQueue::getTrack 0 Jan 12 11:14:04 volumio volumio[974]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":400,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1768216443~MjgxYWQ4MWU3YTc1YzRmYzRkZWJlMTQ0M2Y0NTQwYjQ5NWJiMWJhNg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicyZjI3YjJmNTA3ZjA2Y2I0MzJhYjJmNmEwYzM2MDAwMF82MS5tcDQ/0.flac?token=1768216443~MjgxYWQ4MWU3YTc1YzRmYzRkZWJlMTQ0M2Y0NTQwYjQ5NWJiMWJhNg==","trackType":"tidal"} Jan 12 11:14:04 volumio volumio[974]: verbose: CURRENT POSITION 0 Jan 12 11:14:04 volumio volumio[974]: info: CoreStateMachine::syncState stateService pause Jan 12 11:14:04 volumio volumio[974]: info: CoreStateMachine::syncState currentStatus stop Jan 12 11:14:04 volumio volumio[974]: info: CoreStateMachine::pushState Jan 12 11:14:04 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 11:14:04 volumio volumio[974]: info: CoreCommandRouter::volumioPushState Jan 12 11:14:04 volumio volumio[974]: info: MRS: Pushing multiroomSync output update for this device Jan 12 11:14:04 volumio volumio[974]: info: MRS: Pushing multiroomSync output Jan 12 11:14:04 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:14:04 volumio volumio[974]: info: ControllerMpd::pushState Jan 12 11:14:04 volumio volumio[974]: info: CoreCommandRouter::servicePushState Jan 12 11:14:04 volumio volumio[974]: info: CorePlayQueue::getTrack 0 Jan 12 11:14:04 volumio volumio[974]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":400,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1768216443~MjgxYWQ4MWU3YTc1YzRmYzRkZWJlMTQ0M2Y0NTQwYjQ5NWJiMWJhNg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicyZjI3YjJmNTA3ZjA2Y2I0MzJhYjJmNmEwYzM2MDAwMF82MS5tcDQ/0.flac?token=1768216443~MjgxYWQ4MWU3YTc1YzRmYzRkZWJlMTQ0M2Y0NTQwYjQ5NWJiMWJhNg==","trackType":"tidal"} Jan 12 11:14:04 volumio volumio[974]: verbose: CURRENT POSITION 0 Jan 12 11:14:04 volumio volumio[974]: info: CoreStateMachine::syncState stateService pause Jan 12 11:14:04 volumio volumio[974]: info: CoreStateMachine::syncState currentStatus stop Jan 12 11:14:04 volumio volumio[974]: info: CoreStateMachine::pushState Jan 12 11:14:04 volumio volumio[974]: info: CoreCommandRouter::volumioPushState Jan 12 11:14:04 volumio volumio[974]: info: MRS: Pushing multiroomSync output update for this device Jan 12 11:14:04 volumio volumio[974]: info: MRS: Pushing multiroomSync output Jan 12 11:14:04 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:14:04 volumio volumio[974]: info: ------------------------------ 325ms Jan 12 11:14:04 volumio volumio[974]: info: ------------------------------ 296ms Jan 12 11:14:04 volumio volumio[974]: info: sendMpdCommand playlistinfo took 110 milliseconds Jan 12 11:14:04 volumio volumio[974]: verbose: ControllerMpd::parseTrackInfo Jan 12 11:14:04 volumio volumio[974]: info: ControllerMpd::pushState Jan 12 11:14:04 volumio volumio[974]: info: CoreCommandRouter::servicePushState Jan 12 11:14:04 volumio volumio[974]: info: CorePlayQueue::getTrack 0 Jan 12 11:14:04 volumio volumio[974]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":400,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"0.flac?token=1768216443~MjgxYWQ4MWU3YTc1YzRmYzRkZWJlMTQ0M2Y0NTQwYjQ5NWJiMWJhNg==","artist":null,"album":null,"uri":"http://lgf.audio.tidal.com/mediatracks/CAEaKwgDEicyZjI3YjJmNTA3ZjA2Y2I0MzJhYjJmNmEwYzM2MDAwMF82MS5tcDQ/0.flac?token=1768216443~MjgxYWQ4MWU3YTc1YzRmYzRkZWJlMTQ0M2Y0NTQwYjQ5NWJiMWJhNg==","trackType":"tidal"} Jan 12 11:14:04 volumio volumio[974]: verbose: CURRENT POSITION 0 Jan 12 11:14:04 volumio volumio[974]: info: CoreStateMachine::syncState stateService pause Jan 12 11:14:04 volumio volumio[974]: info: CoreStateMachine::syncState currentStatus stop Jan 12 11:14:04 volumio volumio[974]: info: CoreStateMachine::pushState Jan 12 11:14:04 volumio volumio[974]: info: CoreCommandRouter::volumioPushState Jan 12 11:14:04 volumio volumio[974]: info: MRS: Pushing multiroomSync output update for this device Jan 12 11:14:04 volumio volumio[974]: info: MRS: Pushing multiroomSync output Jan 12 11:14:04 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:14:04 volumio volumio[974]: info: ------------------------------ 333ms Jan 12 11:14:04 volumio volumio[974]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.7jTTEFMMp1T7gO1fxQbEaOdcuXv2.a8a6ae3be1996aebf59fd724964c7125.state.status' Jan 12 11:14:04 volumio volumio[974]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.7jTTEFMMp1T7gO1fxQbEaOdcuXv2.a8a6ae3be1996aebf59fd724964c7125.state.status' Jan 12 11:14:14 volumio kernel: usb 1-1.2: new high-speed USB device number 8 using dwc_otg Jan 12 11:14:14 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Jan 12 11:14:14 volumio kernel: usb 1-1.2: New USB device found, idVendor=2772, idProduct=0226, bcdDevice= 1.10 Jan 12 11:14:14 volumio kernel: usb 1-1.2: New USB device strings: Mfr=1, Product=3, SerialNumber=0 Jan 12 11:14:14 volumio kernel: usb 1-1.2: Product: DAC Box DS2 USB Audio 2.0 Jan 12 11:14:14 volumio kernel: usb 1-1.2: Manufacturer: Project Jan 12 11:14:15 volumio kernel: usbcore: registered new interface driver snd-usb-audio Jan 12 11:14:15 volumio (udev-worker)[4342]: controlC5: Process '/usr/sbin/alsactl -E HOME=/run/alsa -E XDG_RUNTIME_DIR=/run/alsa/runtime restore 5' failed with exit code 99. Jan 12 11:14:15 volumio volumio[974]: info: Jan 12 11:14:15 volumio volumio[974]: ---------------------------- USB Audio Device Attached Jan 12 11:14:15 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Jan 12 11:14:15 volumio volumio[974]: info: CoreCommandRouter::Close All Modals sent Jan 12 11:14:15 volumio volumio[974]: info: Preparing to save Alsa Options, stopping services first Jan 12 11:14:15 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:14:15 volumio volumio[974]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"DAC Box DS2 USB Audio 2.0","alsacard":"D20"},"i2s":false} Jan 12 11:14:15 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 12 11:14:15 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 12 11:14:15 volumio volumio[974]: info: Setting mixer DAC Box DS2 USB Audio 2.0 for card DAC Box DS2 USB Audio 2.0 Jan 12 11:14:15 volumio volumio[974]: info: QobuzConnect: setDeactiveState invoked Jan 12 11:14:15 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:14:15 volumio vtcs[4135]: [2026-01-12 11:14:15.620] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Jan 12 11:14:15 volumio vtcs[4135]: [2026-01-12 11:14:15.622] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Jan 12 11:14:15 volumio sudo[4361]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jan 12 11:14:15 volumio sudo[4361]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:15 volumio volumio[974]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jan 12 11:14:15 volumio volumio[974]: info: Updating Volume Controller Parameters: Device: 5 Name: DAC Box DS2 USB Audio 2.0 Mixer: DAC Box DS2 USB Audio 2.0 Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Jan 12 11:14:15 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jan 12 11:14:15 volumio volumio[974]: info: Disabling external Volume Control Jan 12 11:14:15 volumio volumio[974]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 12 11:14:15 volumio volumio[974]: info: Preparing to generate the ALSA configuration file Jan 12 11:14:15 volumio systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Jan 12 11:14:15 volumio systemd[1]: vtcs.service: Deactivated successfully. Jan 12 11:14:15 volumio systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Jan 12 11:14:15 volumio sudo[4361]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:15 volumio sudo[4369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jan 12 11:14:15 volumio sudo[4369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:15 volumio volumio[974]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 12 11:14:15 volumio volumio[974]: info: Reading ALSA contributions from plugins. Jan 12 11:14:15 volumio sudo[4376]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jan 12 11:14:15 volumio sudo[4376]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:16 volumio sudo[4369]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:16 volumio sudo[4376]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 12 11:14:16 volumio sudo[4383]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jan 12 11:14:16 volumio sudo[4383]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jan 12 11:14:16 volumio volumio[974]: info: VolumeController:: Volume=100 Mute =false Jan 12 11:14:16 volumio volumio[974]: info: CoreStateMachine::pushState Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::volumioPushState Jan 12 11:14:16 volumio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Jan 12 11:14:16 volumio qobuz-connect[4087]: 20260112 11:14:16.235 [4087.4087] INFO SampleApp: Stopping Local configuration server Jan 12 11:14:16 volumio volumio[974]: info: MRS: Pushing multiroomSync output update for this device Jan 12 11:14:16 volumio volumio[974]: info: MRS: Pushing multiroomSync output Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat Jan 12 11:14:16 volumio volumio[974]: info: Asound.conf file written Jan 12 11:14:16 volumio sudo[4395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jan 12 11:14:16 volumio sudo[4395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:16 volumio sudo[4395]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:16 volumio volumio[974]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Jan 12 11:14:16 volumio volumio[974]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Jan 12 11:14:16 volumio volumio[974]: No state is present for card D20 Jan 12 11:14:16 volumio volumio[974]: Found hardware: "USB-Audio" "USB Mixer" "USB2772:0226" "" "" Jan 12 11:14:16 volumio volumio[974]: Hardware is initialized using a generic method Jan 12 11:14:16 volumio volumio[974]: No state is present for card D20 Jan 12 11:14:16 volumio volumio[974]: info: Output device has changed, restarting MPD Jan 12 11:14:16 volumio volumio[974]: info: Output device has changed, restarting Shairport Sync Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 11:14:16 volumio sudo[4403]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 11:14:16 volumio sudo[4403]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:16 volumio sudo[4403]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:16 volumio volumio[974]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 12 11:14:16 volumio volumio[974]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jan 12 11:14:16 volumio sudo[4405]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:16 volumio sudo[4405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:16 volumio volumio[974]: info: QobuzConnect: setDeactiveState invoked Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:14:16 volumio volumio[974]: info: Output device has changed, restarting MPD Jan 12 11:14:16 volumio sudo[4415]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jan 12 11:14:16 volumio sudo[4415]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:16 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 12 11:14:16 volumio volumio[974]: info: Output device has changed, restarting Shairport Sync Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 11:14:16 volumio sudo[4417]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 11:14:16 volumio sudo[4417]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:16 volumio sudo[4417]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:16 volumio sudo[4421]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 11:14:16 volumio sudo[4421]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:16 volumio volumio[974]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 12 11:14:16 volumio volumio[974]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:16 volumio volumio[974]: info: QobuzConnect: setDeactiveState invoked Jan 12 11:14:16 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:14:16 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 12 11:14:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 12 11:14:16 volumio systemd[1]: mpd.service: Consumed 8.194s CPU time. Jan 12 11:14:16 volumio sudo[4430]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jan 12 11:14:16 volumio sudo[4430]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:16 volumio sudo[4432]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jan 12 11:14:16 volumio sudo[4432]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:16 volumio sudo[4415]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:17 volumio sudo[4434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jan 12 11:14:17 volumio sudo[4434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:17 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 12 11:14:17 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 12 11:14:17 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 12 11:14:17 volumio sudo[4443]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jan 12 11:14:17 volumio sudo[4443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:17 volumio volumio[974]: info: MPD Permissions set Jan 12 11:14:17 volumio volumio[974]: info: MPD Permissions set Jan 12 11:14:17 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio sudo[4454]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jan 12 11:14:17 volumio sudo[4454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:17 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 12 11:14:17 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Jan 12 11:14:17 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Jan 12 11:14:17 volumio systemd[1]: setdatetime-helper.service: Consumed 2.171s CPU time. Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: Starting Shairport Sync Jan 12 11:14:17 volumio volumio[974]: info: Starting Shairport Sync Jan 12 11:14:17 volumio volumio[974]: info: Preparing to generate the ALSA configuration file Jan 12 11:14:17 volumio sudo[4471]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 12 11:14:17 volumio sudo[4471]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:17 volumio sudo[4473]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 12 11:14:17 volumio sudo[4473]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:17 volumio volumio[974]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 12 11:14:17 volumio volumio[974]: info: Reading ALSA contributions from plugins. Jan 12 11:14:17 volumio sudo[4443]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:17 volumio volumio[974]: info: Asound.conf file written Jan 12 11:14:17 volumio sudo[4454]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:17 volumio sudo[4430]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:17 volumio sudo[4477]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jan 12 11:14:17 volumio sudo[4477]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:17 volumio sudo[4479]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jan 12 11:14:17 volumio sudo[4479]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:17 volumio sudo[4479]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:17 volumio sudo[4480]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jan 12 11:14:17 volumio sudo[4480]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:17 volumio sudo[4461]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 12 11:14:17 volumio sudo[4461]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 12 11:14:17 volumio sudo[4432]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:17 volumio sudo[4461]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:17 volumio volumio[974]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2 Jan 12 11:14:17 volumio volumio[974]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2 Jan 12 11:14:17 volumio volumio[974]: No state is present for card D20 Jan 12 11:14:17 volumio volumio[974]: Found hardware: "USB-Audio" "USB Mixer" "USB2772:0226" "" "" Jan 12 11:14:17 volumio volumio[974]: Hardware is initialized using a generic method Jan 12 11:14:17 volumio volumio[974]: No state is present for card D20 Jan 12 11:14:17 volumio volumio[974]: info: Output device has changed, restarting MPD Jan 12 11:14:17 volumio sudo[4434]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:17 volumio volumio[974]: info: Output device has changed, restarting Shairport Sync Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 11:14:17 volumio sudo[4492]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 11:14:17 volumio sudo[4492]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:17 volumio sudo[4492]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:17 volumio sudo[4494]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 11:14:17 volumio volumio[974]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 12 11:14:17 volumio volumio[974]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jan 12 11:14:17 volumio sudo[4494]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:17 volumio volumio[974]: info: QobuzConnect: setDeactiveState invoked Jan 12 11:14:17 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:14:17 volumio qobuz-connect[4087]: 20260112 11:14:17.946 [4087.4087] INFO SampleApp: shat down connection on UNIX socket Jan 12 11:14:17 volumio volumio[974]: info: Preparing to generate the ALSA configuration file Jan 12 11:14:18 volumio systemd[1]: qobuz-connect.service: Deactivated successfully. Jan 12 11:14:18 volumio systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Jan 12 11:14:18 volumio sudo[4506]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jan 12 11:14:18 volumio sudo[4506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:18 volumio volumio[974]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Jan 12 11:14:18 volumio sudo[4509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jan 12 11:14:18 volumio volumio[974]: info: Reading ALSA contributions from plugins. Jan 12 11:14:18 volumio sudo[4509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:18 volumio volumio[974]: info: MPD Permissions set Jan 12 11:14:18 volumio volumio[974]: info: QobuzConnect: Qobuz Connect client [object Object] disconnected Jan 12 11:14:18 volumio volumio[974]: info: QobuzConnect: setDeactiveState invoked Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio sudo[4515]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jan 12 11:14:18 volumio sudo[4515]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Jan 12 11:14:18 volumio volumio[974]: info: Starting Shairport Sync Jan 12 11:14:18 volumio sudo[4480]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:18 volumio sudo[4383]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 12 11:14:18 volumio sudo[4477]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 12 11:14:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 11:14:18 volumio systemd[1]: shairport-sync.service: Consumed 2.528s CPU time. Jan 12 11:14:18 volumio volumio[974]: info: Asound.conf file unchanged, so no further update is needed Jan 12 11:14:18 volumio volumio[974]: info: Output device has changed, restarting MPD Jan 12 11:14:18 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 12 11:14:18 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 12 11:14:18 volumio sudo[4525]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 12 11:14:18 volumio sudo[4525]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:18 volumio volumio[974]: info: Output device has changed, restarting Shairport Sync Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 11:14:18 volumio sudo[4527]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 12 11:14:18 volumio sudo[4527]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:18 volumio volumio[974]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 12 11:14:18 volumio sudo[4530]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 12 11:14:18 volumio volumio[974]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Jan 12 11:14:18 volumio sudo[4530]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio sudo[4527]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:18 volumio volumio[974]: info: QobuzConnect: setDeactiveState invoked Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:14:18 volumio sudo[4540]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jan 12 11:14:18 volumio sudo[4540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:18 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 12 11:14:18 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 12 11:14:18 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 12 11:14:18 volumio sudo[4515]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:18 volumio sudo[4543]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Jan 12 11:14:18 volumio sudo[4543]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:18 volumio volumio[974]: info: MPD Permissions set Jan 12 11:14:18 volumio volumio[974]: info: Executing endpoint qc_getconfig Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig Jan 12 11:14:18 volumio sudo[4549]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jan 12 11:14:18 volumio sudo[4549]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:18 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 12 11:14:18 volumio sudo[4552]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service Jan 12 11:14:18 volumio sudo[4552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:18 volumio qobuz-connect[4517]: 20260112 11:14:18.689 [4517.4517] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket Jan 12 11:14:18 volumio volumio[974]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object] Jan 12 11:14:18 volumio volumio[974]: info: QobuzConnect: QOBUZ Connect daemon connected Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio qobuz-connect[4517]: 20260112 11:14:18.702 [4517.4517] INFO VolumeManager: [0x1371368]: Setting new playback volume: 75 Jan 12 11:14:18 volumio qobuz-connect[4517]: 20260112 11:14:18.702 [4517.4517] INFO VolumeManager: [0x1371368]: Setting new mute state: 0 Jan 12 11:14:18 volumio qobuz-connect[4517]: 20260112 11:14:18.702 [4517.4517] INFO QobuzConnect: [0x1371d38]: Client initialized! Jan 12 11:14:18 volumio qobuz-connect[4517]: 20260112 11:14:18.702 [4517.4517] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 12 11:14:18 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 12 11:14:18 volumio volumio[974]: info: Starting Shairport Sync Jan 12 11:14:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 11:14:18 volumio qobuz-connect[4517]: 20260112 11:14:18.774 [4517.4517] INFO LocalConfigManager: [0x1370c48]: Starting Local Configuration server Jan 12 11:14:18 volumio qobuz-connect[4517]: 20260112 11:14:18.774 [4517.4517] INFO SampleApp: Starting Local configuration server Jan 12 11:14:18 volumio qobuz-connect[4517]: 20260112 11:14:18.775 [4517.4517] INFO SampleApp: Connected to UNIX socket client 0x135b818 Jan 12 11:14:18 volumio sudo[4471]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:18 volumio sudo[4473]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:18 volumio qobuz-connect[4517]: 20260112 11:14:18.840 [4517.4517] INFO SampleApp: Playback volume changed: 75 Jan 12 11:14:18 volumio volumio[974]: info: CoreCommandRouter::volumioGetState Jan 12 11:14:18 volumio sudo[4568]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 12 11:14:18 volumio volumio[974]: info: Shairport-Sync Started Jan 12 11:14:18 volumio sudo[4568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:18 volumio volumio[974]: info: TidalConnect service stoped! Jan 12 11:14:18 volumio volumio[974]: info: Shairport-Sync Started Jan 12 11:14:19 volumio volumio[974]: info: TidalConnect service stoped! Jan 12 11:14:19 volumio sudo[4506]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:19 volumio sudo[4509]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:19 volumio volumio[974]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Jan 12 11:14:19 volumio volumio[974]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Jan 12 11:14:19 volumio sudo[4595]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Jan 12 11:14:19 volumio sudo[4595]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:19 volumio sudo[4558]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 12 11:14:19 volumio sudo[4558]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 12 11:14:19 volumio sudo[4558]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:19 volumio sudo[4552]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:19 volumio sudo[4599]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service Jan 12 11:14:19 volumio sudo[4599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 12 11:14:19 volumio sudo[4543]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:19 volumio sudo[4540]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:19 volumio volumio[974]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 11:14:19 volumio volumio[974]: Error: Command failed: /usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3 Jan 12 11:14:19 volumio volumio[974]: Job for vtcs.service canceled. Jan 12 11:14:19 volumio volumio[974]: at ChildProcess.exithandler (node:child_process:421:12) Jan 12 11:14:19 volumio volumio[974]: at ChildProcess.emit (node:events:514:28) Jan 12 11:14:19 volumio volumio[974]: at maybeClose (node:internal/child_process:1105:16) Jan 12 11:14:19 volumio volumio[974]: at ChildProcess._handle.onexit (node:internal/child_process:305:5) { Jan 12 11:14:19 volumio volumio[974]: code: 1, Jan 12 11:14:19 volumio volumio[974]: killed: false, Jan 12 11:14:19 volumio volumio[974]: signal: null, Jan 12 11:14:19 volumio volumio[974]: cmd: '/usr/bin/sudo /bin/systemctl stop vtcs.service && sleep 3', Jan 12 11:14:19 volumio volumio[974]: stdout: '', Jan 12 11:14:19 volumio volumio[974]: stderr: 'Job for vtcs.service canceled.\n' Jan 12 11:14:19 volumio volumio[974]: } Jan 12 11:14:19 volumio volumio[974]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 12 11:14:19 volumio qobuz-connect[4517]: 20260112 11:14:19.669 [4517.4517] INFO SampleApp: Stopping Local configuration server Jan 12 11:14:19 volumio systemd[1]: Stopping qobuz-connect.service - Volumio Qobuz Connect Service... Jan 12 11:14:19 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 12 11:14:19 volumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Jan 12 11:14:19 volumio sudo[4595]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:19 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 12 11:14:19 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 11:14:19 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 12 11:14:19 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 12 11:14:19 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 12 11:14:19 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 12 11:14:19 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 12 11:14:19 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 12 11:14:19 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 12 11:14:20 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 12 11:14:20 volumio sudo[4568]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:20 volumio sudo[4525]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:20 volumio sudo[4617]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 12 11:14:20 volumio sudo[4617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 12 11:14:20 volumio sudo[4617]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:20 volumio qobuz-connect[4517]: 20260112 11:14:20.797 [4517.4517] INFO SampleApp: shat down connection on UNIX socket Jan 12 11:14:20 volumio systemd[1]: qobuz-connect.service: Deactivated successfully. Jan 12 11:14:20 volumio systemd[1]: Stopped qobuz-connect.service - Volumio Qobuz Connect Service. Jan 12 11:14:20 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service. Jan 12 11:14:20 volumio sudo[4599]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:20 volumio sudo[4549]: pam_unix(sudo:session): session closed for user root Jan 12 11:14:21 volumio sudo[4638]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-12 11:13' Jan 12 11:14:21 volumio sudo[4638]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"