-- Logs begin at Sat 2025-03-15 18:43:33 EDT, end at Sat 2025-03-15 20:33:51 EDT. -- Mar 15 20:32:06 volumiomain go-librespot[1325]: time="2025-03-15T20:32:06-04:00" level=trace msg="sent dealer ping" Mar 15 20:32:06 volumiomain go-librespot[1325]: time="2025-03-15T20:32:06-04:00" level=trace msg="received dealer pong" Mar 15 20:32:36 volumiomain go-librespot[1325]: time="2025-03-15T20:32:36-04:00" level=trace msg="sent dealer ping" Mar 15 20:32:36 volumiomain go-librespot[1325]: time="2025-03-15T20:32:36-04:00" level=trace msg="received dealer pong" Mar 15 20:32:53 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 15 20:32:53 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 15 20:32:53 volumiomain volumio[964]: info: Discovery: Getting this device information Mar 15 20:32:53 volumiomain volumio[964]: info: CoreCommandRouter::volumioGetState Mar 15 20:32:53 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 15 20:32:53 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 15 20:32:53 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 15 20:32:53 volumiomain volumio[964]: info: Discovery: Getting this device information Mar 15 20:32:53 volumiomain volumio[964]: info: CoreCommandRouter::volumioGetState Mar 15 20:32:53 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 15 20:32:53 volumiomain volumio[964]: verbose: New Socket.io Connection to 192.168.198.140:3000 from 192.168.198.219 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Mar 15 20:32:54 volumiomain volumio[964]: verbose: New Socket.io Connection to 192.168.198.140 from 192.168.198.219 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_3_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 9 Mar 15 20:32:54 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 15 20:32:54 volumiomain volumio[964]: info: CoreCommandRouter::volumioGetVisibleSources Mar 15 20:32:54 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 15 20:32:54 volumiomain volumio[964]: info: CoreCommandRouter::volumioGetState Mar 15 20:32:54 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Mar 15 20:32:54 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 15 20:32:54 volumiomain volumio[964]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Mar 15 20:32:54 volumiomain volumio[964]: info: Received Get System Info Mar 15 20:32:54 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 15 20:32:54 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 15 20:32:54 volumiomain volumio[964]: info: Discovery: Getting this device information Mar 15 20:32:54 volumiomain volumio[964]: info: CoreCommandRouter::volumioGetState Mar 15 20:32:54 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 15 20:32:54 volumiomain volumio[964]: info: CoreCommandRouter::volumioGetState Mar 15 20:32:54 volumiomain volumio[964]: info: Listing playlists Mar 15 20:32:54 volumiomain volumio[964]: info: CoreCommandRouter::volumioGetQueue Mar 15 20:32:54 volumiomain volumio[964]: info: CoreStateMachine::getQueue Mar 15 20:32:54 volumiomain volumio[964]: info: CorePlayQueue::getQueue Mar 15 20:32:54 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 15 20:32:55 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 15 20:32:55 volumiomain volumio[964]: info: Received Get System Info Mar 15 20:32:55 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 15 20:32:55 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 15 20:32:55 volumiomain volumio[964]: info: Discovery: Getting this device information Mar 15 20:32:55 volumiomain volumio[964]: info: CoreCommandRouter::volumioGetState Mar 15 20:32:55 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 15 20:33:06 volumiomain go-librespot[1325]: time="2025-03-15T20:33:06-04:00" level=trace msg="sent dealer ping" Mar 15 20:33:06 volumiomain go-librespot[1325]: time="2025-03-15T20:33:06-04:00" level=trace msg="received dealer pong" Mar 15 20:33:14 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 15 20:33:14 volumiomain volumio[964]: info: browseTIDALUri took 342 milliseconds Mar 15 20:33:14 volumiomain volumio[964]: info: Preload queue cleared Mar 15 20:33:14 volumiomain volumio[964]: info: Preload queue cleared Mar 15 20:33:16 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 15 20:33:16 volumiomain volumio[964]: info: browseTIDALUri took 294 milliseconds Mar 15 20:33:16 volumiomain volumio[964]: info: Preload queue cleared Mar 15 20:33:17 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 15 20:33:17 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 15 20:33:17 volumiomain volumio[964]: info: Discovery: Getting this device information Mar 15 20:33:17 volumiomain volumio[964]: info: CoreCommandRouter::volumioGetState Mar 15 20:33:17 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 15 20:33:33 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: tidal , handleBrowseUri Mar 15 20:33:33 volumiomain volumio[964]: info: browseTIDALUri took 617 milliseconds Mar 15 20:33:33 volumiomain volumio[964]: info: Preload queue cleared Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/103398058 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/77614520 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/3009887 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/635957 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/72598720 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/58990516 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/79169807 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/79279108 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/2211776 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/2205831 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/7861997 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/2022555 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/75734800 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/325152 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/49794929 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/33345894 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/299144 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/1186619 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/75062708 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/51584179 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/1699542 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/3128848 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/79169804 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/4081109 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/2211780 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/158822 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/301730 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/391244 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/49152382 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/61471 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/6874029 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/192089980 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/36298011 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/325158 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/2211777 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/35083335 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/2210180 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/11009841 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/7985597 Mar 15 20:33:33 volumiomain volumio[964]: info: Preloading song: tidal://song/50178 Mar 15 20:33:33 volumiomain volumio[964]: info: Exploding uri tidal://song/103398058 in service tidal Mar 15 20:33:33 volumiomain volumio[964]: info: Exploding uri tidal://song/77614520 in service tidal Mar 15 20:33:33 volumiomain volumio[964]: info: Exploding uri tidal://song/3009887 in service tidal Mar 15 20:33:33 volumiomain volumio[964]: info: Exploding uri tidal://song/635957 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/72598720 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/58990516 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 255 milliseconds Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 239 milliseconds Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/79169807 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/79279108 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 242 milliseconds Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/2211776 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 272 milliseconds Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 214 milliseconds Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/2205831 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 213 milliseconds Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/7861997 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 251 milliseconds Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/2022555 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/75734800 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 274 milliseconds Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/325152 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/49794929 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 348 milliseconds Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/33345894 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 336 milliseconds Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/299144 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 282 milliseconds Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/1186619 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 379 milliseconds Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/75062708 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 339 milliseconds Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/51584179 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 371 milliseconds Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/1699542 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 330 milliseconds Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 286 milliseconds Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/3128848 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: Exploding uri tidal://song/79169804 in service tidal Mar 15 20:33:34 volumiomain volumio[964]: info: explodeTIDALUri took 348 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/4081109 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 273 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/2211780 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/158822 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 414 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/301730 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 399 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 340 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/391244 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/49152382 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 386 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/61471 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/6874029 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 469 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/192089980 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 409 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 394 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/36298011 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/325158 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 353 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/2211777 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 435 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/35083335 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 362 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 431 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/2210180 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 364 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/11009841 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/7985597 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: Exploding uri tidal://song/50178 in service tidal Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 435 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 340 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 462 milliseconds Mar 15 20:33:35 volumiomain volumio[964]: info: explodeTIDALUri took 407 milliseconds Mar 15 20:33:36 volumiomain volumio[964]: info: explodeTIDALUri took 491 milliseconds Mar 15 20:33:36 volumiomain volumio[964]: info: explodeTIDALUri took 434 milliseconds Mar 15 20:33:36 volumiomain volumio[964]: info: explodeTIDALUri took 472 milliseconds Mar 15 20:33:36 volumiomain volumio[964]: info: explodeTIDALUri took 306 milliseconds Mar 15 20:33:36 volumiomain volumio[964]: info: explodeTIDALUri took 343 milliseconds Mar 15 20:33:36 volumiomain go-librespot[1325]: time="2025-03-15T20:33:36-04:00" level=trace msg="received accesspoint ping" Mar 15 20:33:36 volumiomain volumio[964]: info: explodeTIDALUri took 472 milliseconds Mar 15 20:33:36 volumiomain go-librespot[1325]: time="2025-03-15T20:33:36-04:00" level=trace msg="received accesspoint pong ack" Mar 15 20:33:36 volumiomain go-librespot[1325]: time="2025-03-15T20:33:36-04:00" level=trace msg="sent dealer ping" Mar 15 20:33:36 volumiomain go-librespot[1325]: time="2025-03-15T20:33:36-04:00" level=trace msg="received dealer pong" Mar 15 20:33:45 volumiomain volumio[964]: info: Preload queue cleared Mar 15 20:33:45 volumiomain volumio[964]: info: CoreCommandRouter::volumioReplaceandPlayItems Mar 15 20:33:45 volumiomain volumio[964]: info: CoreStateMachine::ClearQueue Mar 15 20:33:45 volumiomain volumio[964]: info: CoreStateMachine::stop Mar 15 20:33:45 volumiomain volumio[964]: info: CoreStateMachine::serviceStop Mar 15 20:33:45 volumiomain volumio[964]: info: Received STOP, but no service to execute it Mar 15 20:33:45 volumiomain volumio[964]: info: CorePlayQueue::clearPlayQueue Mar 15 20:33:45 volumiomain volumio[964]: info: CorePlayQueue::saveQueue Mar 15 20:33:45 volumiomain volumio[964]: info: CoreCommandRouter::volumioPushQueue Mar 15 20:33:45 volumiomain volumio[964]: info: CoreStateMachine::addQueueItems Mar 15 20:33:45 volumiomain volumio[964]: info: CorePlayQueue::addQueueItems Mar 15 20:33:45 volumiomain volumio[964]: info: Preload queue cleared Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/103398058 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/103398058 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/77614520 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/77614520 Mar 15 20:33:45 volumiomain volumio[964]: info: CoreCommandRouter::volumioPushQueue Mar 15 20:33:45 volumiomain volumio[964]: info: CorePlayQueue::saveQueue Mar 15 20:33:45 volumiomain volumio[964]: info: CoreStateMachine::updateTrackBlock Mar 15 20:33:45 volumiomain volumio[964]: info: CorePlayQueue::getTrackBlock Mar 15 20:33:45 volumiomain volumio[964]: info: CoreCommandRouter::volumioPlay Mar 15 20:33:45 volumiomain volumio[964]: verbose: UNSET VOLATILE: Service: undefined Mar 15 20:33:45 volumiomain volumio[964]: info: Stopping Airplay Playback and sending pause command to client via USR2 Mar 15 20:33:45 volumiomain volumio[964]: info: CoreStateMachine::play index 1 Mar 15 20:33:45 volumiomain volumio[964]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 15 20:33:45 volumiomain volumio[964]: info: CoreStateMachine::addQueueItems Mar 15 20:33:45 volumiomain volumio[964]: info: CorePlayQueue::addQueueItems Mar 15 20:33:45 volumiomain volumio[964]: info: Preload queue cleared Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/3009887 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/3009887 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/635957 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/635957 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/72598720 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/72598720 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/58990516 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/58990516 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/79169807 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/79169807 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/79279108 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/79279108 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/2211776 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/2211776 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/2205831 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/2205831 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/7861997 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/7861997 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/2022555 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/2022555 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/75734800 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/75734800 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/325152 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/325152 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/49794929 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/49794929 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/33345894 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/33345894 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/299144 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/299144 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/1186619 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/1186619 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/75062708 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/75062708 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/51584179 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/51584179 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/1699542 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/1699542 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/3128848 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/3128848 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/79169804 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/79169804 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/4081109 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/4081109 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/2211780 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/2211780 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/158822 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/158822 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/301730 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/301730 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/391244 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/391244 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/49152382 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/49152382 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/61471 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/61471 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/6874029 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/6874029 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/192089980 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/192089980 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/36298011 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/36298011 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/325158 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/325158 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/2211777 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/2211777 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/35083335 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/35083335 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/2210180 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/2210180 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/11009841 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/11009841 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/7985597 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/7985597 Mar 15 20:33:45 volumiomain volumio[964]: info: Adding Item to queue: tidal://song/50178 Mar 15 20:33:45 volumiomain volumio[964]: info: Using cached record of: tidal://song/50178 Mar 15 20:33:45 volumiomain volumio[964]: info: CoreStateMachine::stop Mar 15 20:33:45 volumiomain volumio[964]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 15 20:33:45 volumiomain volumio[964]: info: CoreCommandRouter::volumioPushQueue Mar 15 20:33:45 volumiomain volumio[964]: info: CorePlayQueue::saveQueue Mar 15 20:33:45 volumiomain sudo[16228]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 1578 Mar 15 20:33:45 volumiomain sudo[16228]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 20:33:45 volumiomain volumio[964]: info: CoreStateMachine::play index undefined Mar 15 20:33:45 volumiomain volumio[964]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 15 20:33:45 volumiomain volumio[964]: info: CoreStateMachine::updateTrackBlock Mar 15 20:33:45 volumiomain volumio[964]: info: CorePlayQueue::getTrackBlock Mar 15 20:33:45 volumiomain volumio[964]: info: CorePlayQueue::getTrack 1 Mar 15 20:33:45 volumiomain volumio[964]: info: CoreStateMachine::startPlaybackTimer Mar 15 20:33:45 volumiomain volumio[964]: info: CorePlayQueue::getTrack 1 Mar 15 20:33:45 volumiomain volumio[964]: info: [1742085225633] ControllerTidal::clearAddPlayTrack Mar 15 20:33:45 volumiomain volumio[964]: info: Getting stream with soundQuality LOSSLESS Mar 15 20:33:45 volumiomain volumio[964]: verbose: ControllerMpd::sendMpdCommand stop Mar 15 20:33:45 volumiomain sudo[16228]: pam_unix(sudo:session): session closed for user root Mar 15 20:33:45 volumiomain volumio[964]: info: sendMpdCommand stop took 37 milliseconds Mar 15 20:33:45 volumiomain volumio[964]: verbose: ControllerMpd::sendMpdCommand clear Mar 15 20:33:45 volumiomain volumio[964]: info: Mar 15 20:33:45 volumiomain volumio[964]: ---------------------------- MPD announces system playlist update Mar 15 20:33:45 volumiomain volumio[964]: info: Ignoring MPD Status Update Mar 15 20:33:45 volumiomain volumio[964]: info: sendMpdCommand clear took 7 milliseconds Mar 15 20:33:45 volumiomain volumio[964]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/77614520&soundQuality=LOSSLESS" Mar 15 20:33:45 volumiomain volumio[964]: info: Shairport-Sync paused with USR2 Mar 15 20:33:45 volumiomain volumio[964]: error: updateQueue error: null Mar 15 20:33:45 volumiomain volumio[964]: info: Mar 15 20:33:45 volumiomain volumio[964]: ---------------------------- MPD announces system playlist update Mar 15 20:33:45 volumiomain volumio[964]: info: Ignoring MPD Status Update Mar 15 20:33:45 volumiomain volumio[964]: info: ------------------------------ 20ms Mar 15 20:33:45 volumiomain volumio[964]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/77614520&soundQuality=LOSSLESS" took 16 milliseconds Mar 15 20:33:45 volumiomain volumio[964]: info: CoreStateMachine::setConsumeUpdateService mpd Mar 15 20:33:45 volumiomain volumio[964]: verbose: ControllerMpd::sendMpdCommand play Mar 15 20:33:45 volumiomain volumio[964]: info: ------------------------------ 10ms Mar 15 20:33:45 volumiomain volumio[964]: info: sendMpdCommand play took 6 milliseconds Mar 15 20:33:45 volumiomain volumio[964]: STREAMING PROXY: Handling url /?data=tidal://song/77614520&soundQuality=LOSSLESS Mar 15 20:33:45 volumiomain volumio[964]: info: Executing endpoint getStreamUrltidal Mar 15 20:33:45 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Mar 15 20:33:46 volumiomain volumio[964]: info: getStreamUrl took 242 milliseconds Mar 15 20:33:46 volumiomain volumio[964]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKAgDEiRmNDgxMDM4YmU4ODQwMDc0ZTIwYTAzN2Y2NTE5MTFlMC5tcDQ/0.flac?Expires=1742088826&Signature=Qq51NMHBh3v1W3xEhBa2OwmTH0CO5yqhUH8l~ggKLxOiRsk7vdK0Jbq1H~Sdfge36FcLrPqF0ilZywGaaYdqmPLDza~kkEBEy4Gl8abEtviTpZhi56FH4IXwZ1U4zDRe9CM2Ww0qRrKkVlulao1ypllwW36YhTG09y~loEpviGR8vzKjRH47deKfARGrqsXFTxQu-GLHzwkEH-RopwqR9eApI~q8ES0YhUd5V7lMBIXb2x6jQJOT5CWnMuBaWqLyRjfW82f2mbQOQHPC~HlE5BsYCEMSxw1CiRy5XYKaSGLa80iWe4lXPGhz5Ha-rlWoROkKZvH3MCDsbBPgz9wHUg__&Key-Pair-Id=K14LZCZ9QUI4JL Mar 15 20:33:46 volumiomain volumio[964]: STREAMING PROXY: Response: 200, length: 32267057 Mar 15 20:33:46 volumiomain volumio[964]: info: Mar 15 20:33:46 volumiomain volumio[964]: ---------------------------- MPD announces state update: player Mar 15 20:33:46 volumiomain volumio[964]: info: ControllerMpd::getState Mar 15 20:33:46 volumiomain volumio[964]: verbose: ControllerMpd::sendMpdCommand status Mar 15 20:33:46 volumiomain volumio[964]: info: Mar 15 20:33:46 volumiomain volumio[964]: ---------------------------- MPD announces state update: player Mar 15 20:33:46 volumiomain volumio[964]: info: sendMpdCommand status took 15 milliseconds Mar 15 20:33:46 volumiomain volumio[964]: info: ControllerMpd::getState Mar 15 20:33:46 volumiomain volumio[964]: verbose: ControllerMpd::sendMpdCommand status Mar 15 20:33:46 volumiomain volumio[964]: verbose: ControllerMpd::parseState Mar 15 20:33:46 volumiomain volumio[964]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 15 20:33:46 volumiomain volumio[964]: info: sendMpdCommand status took 11 milliseconds Mar 15 20:33:46 volumiomain volumio[964]: info: sendMpdCommand playlistinfo took 7 milliseconds Mar 15 20:33:46 volumiomain volumio[964]: verbose: ControllerMpd::parseState Mar 15 20:33:46 volumiomain volumio[964]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 15 20:33:46 volumiomain volumio[964]: verbose: ControllerMpd::parseTrackInfo Mar 15 20:33:46 volumiomain volumio[964]: info: ControllerMpd::pushState Mar 15 20:33:46 volumiomain volumio[964]: info: CoreCommandRouter::servicePushState Mar 15 20:33:46 volumiomain volumio[964]: info: CorePlayQueue::getTrack 1 Mar 15 20:33:46 volumiomain volumio[964]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":286,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"77614520&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/77614520&soundQuality=LOSSLESS","trackType":"tidal"} Mar 15 20:33:46 volumiomain volumio[964]: verbose: CURRENT POSITION 1 Mar 15 20:33:46 volumiomain volumio[964]: info: CoreStateMachine::syncState stateService play Mar 15 20:33:46 volumiomain volumio[964]: info: CoreStateMachine::syncState currentStatus stop Mar 15 20:33:46 volumiomain volumio[964]: info: ------------------------------ 49ms Mar 15 20:33:46 volumiomain volumio[964]: info: sendMpdCommand playlistinfo took 23 milliseconds Mar 15 20:33:46 volumiomain volumio[964]: verbose: ControllerMpd::parseTrackInfo Mar 15 20:33:46 volumiomain volumio[964]: info: ControllerMpd::pushState Mar 15 20:33:46 volumiomain volumio[964]: info: CoreCommandRouter::servicePushState Mar 15 20:33:46 volumiomain volumio[964]: info: CorePlayQueue::getTrack 1 Mar 15 20:33:46 volumiomain volumio[964]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":286,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"77614520&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/77614520&soundQuality=LOSSLESS","trackType":"tidal"} Mar 15 20:33:46 volumiomain volumio[964]: verbose: CURRENT POSITION 1 Mar 15 20:33:46 volumiomain volumio[964]: info: CoreStateMachine::syncState stateService play Mar 15 20:33:46 volumiomain volumio[964]: info: CoreStateMachine::syncState currentStatus play Mar 15 20:33:46 volumiomain volumio[964]: info: Received an update from plugin. extracting info from payload Mar 15 20:33:46 volumiomain volumio[964]: info: CoreStateMachine::pushState Mar 15 20:33:46 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 15 20:33:46 volumiomain volumio[964]: info: CoreCommandRouter::volumioPushState Mar 15 20:33:46 volumiomain volumio[964]: info: MRS: Pushing multiroomSync output update for this device Mar 15 20:33:46 volumiomain volumio[964]: info: MRS: Pushing multiroomSync output Mar 15 20:33:46 volumiomain volumio[964]: info: CoreStateMachine::pushState Mar 15 20:33:46 volumiomain volumio[964]: info: CoreCommandRouter::volumioPushState Mar 15 20:33:46 volumiomain volumio[964]: info: MRS: Pushing multiroomSync output update for this device Mar 15 20:33:46 volumiomain volumio[964]: info: MRS: Pushing multiroomSync output Mar 15 20:33:46 volumiomain volumio[964]: info: ------------------------------ 113ms Mar 15 20:33:46 volumiomain volumio[964]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Mar 15 20:33:46 volumiomain volumio[964]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Mar 15 20:33:46 volumiomain volumio[964]: info: [LastFM] Current track has sufficient metadata: title (Cellphone's Dead) and artist (Beck) passed on explicitly Mar 15 20:33:46 volumiomain volumio[964]: info: Restarting Shairport-Sync after stop Mar 15 20:33:46 volumiomain sudo[16239]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Mar 15 20:33:46 volumiomain sudo[16239]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 15 20:33:46 volumiomain systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Mar 15 20:33:46 volumiomain shairport-sync[1578]: {"time":1742080017493,"response":"stopAirplayPlayback Success"} Mar 15 20:33:46 volumiomain systemd[1]: shairport-sync.service: Succeeded. Mar 15 20:33:46 volumiomain systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Mar 15 20:33:46 volumiomain volumio[964]: ------------------------------------ BT MESSAGE: BT STATUS: running Mar 15 20:33:46 volumiomain volumio[964]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Mar 15 20:33:47 volumiomain systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Mar 15 20:33:47 volumiomain sudo[16239]: pam_unix(sudo:session): session closed for user root Mar 15 20:33:47 volumiomain volumio[964]: info: Shairport-Sync retarted Mar 15 20:33:47 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 15 20:33:47 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 15 20:33:47 volumiomain volumio[964]: info: Discovery: Getting this device information Mar 15 20:33:47 volumiomain volumio[964]: info: CoreCommandRouter::volumioGetState Mar 15 20:33:47 volumiomain volumio[964]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 15 20:33:49 volumiomain volumio[964]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 15 20:33:49 volumiomain volumio[964]: TypeError: Cannot read property '@' of null Mar 15 20:33:49 volumiomain volumio[964]: at Object.callback (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:342:14) Mar 15 20:33:49 volumiomain volumio[964]: at /data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:60:13 Mar 15 20:33:49 volumiomain volumio[964]: at Parser. (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:304:18) Mar 15 20:33:49 volumiomain volumio[964]: at Parser.emit (events.js:315:20) Mar 15 20:33:49 volumiomain volumio[964]: at Parser.exports.Parser.Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:314:16) Mar 15 20:33:49 volumiomain volumio[964]: at Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:5:59) Mar 15 20:33:49 volumiomain volumio[964]: at IncomingMessage. (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:58:14) Mar 15 20:33:49 volumiomain volumio[964]: at IncomingMessage.emit (events.js:327:22) Mar 15 20:33:49 volumiomain volumio[964]: at endReadableNT (internal/streams/readable.js:1327:12) Mar 15 20:33:49 volumiomain volumio[964]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Mar 15 20:33:49 volumiomain volumio[964]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 15 20:33:51 volumiomain sudo[16269]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-15 20:32 Mar 15 20:33:51 volumiomain sudo[16269]: 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"