-- Logs begin at Thu 2019-02-14 19:11:58 JST, end at Sun 2025-05-18 00:48:58 JST. -- May 18 00:47:00 tinkermio go-librespot[1462]: time="2025-05-18T00:47:00+09:00" level=trace msg="sent dealer ping" May 18 00:47:00 tinkermio go-librespot[1462]: time="2025-05-18T00:47:00+09:00" level=trace msg="received dealer pong" May 18 00:47:06 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:47:06 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:47:06 tinkermio volumio[1106]: info: Discovery: Getting this device information May 18 00:47:06 tinkermio volumio[1106]: info: CoreCommandRouter::volumioGetState May 18 00:47:06 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 28 May 18 00:47:06 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:47:30 tinkermio go-librespot[1462]: time="2025-05-18T00:47:30+09:00" level=trace msg="sent dealer ping" May 18 00:47:30 tinkermio go-librespot[1462]: time="2025-05-18T00:47:30+09:00" level=trace msg="received dealer pong" May 18 00:47:36 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:47:36 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:47:36 tinkermio volumio[1106]: info: Discovery: Getting this device information May 18 00:47:36 tinkermio volumio[1106]: info: CoreCommandRouter::volumioGetState May 18 00:47:36 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 28 May 18 00:47:36 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:47:59 tinkermio go-librespot[1462]: time="2025-05-18T00:47:59+09:00" level=trace msg="received accesspoint ping" May 18 00:47:59 tinkermio go-librespot[1462]: time="2025-05-18T00:47:59+09:00" level=trace msg="received accesspoint pong ack" May 18 00:48:00 tinkermio go-librespot[1462]: time="2025-05-18T00:48:00+09:00" level=trace msg="sent dealer ping" May 18 00:48:00 tinkermio go-librespot[1462]: time="2025-05-18T00:48:00+09:00" level=trace msg="received dealer pong" May 18 00:48:06 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:48:06 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:48:06 tinkermio volumio[1106]: info: Discovery: Getting this device information May 18 00:48:06 tinkermio volumio[1106]: info: CoreCommandRouter::volumioGetState May 18 00:48:06 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 28 May 18 00:48:06 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:48:30 tinkermio go-librespot[1462]: time="2025-05-18T00:48:30+09:00" level=trace msg="sent dealer ping" May 18 00:48:30 tinkermio go-librespot[1462]: time="2025-05-18T00:48:30+09:00" level=trace msg="received dealer pong" May 18 00:48:36 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 18 00:48:36 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 18 00:48:36 tinkermio volumio[1106]: info: Discovery: Getting this device information May 18 00:48:36 tinkermio volumio[1106]: info: CoreCommandRouter::volumioGetState May 18 00:48:36 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 28 May 18 00:48:36 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 18 00:48:40 tinkermio volumio[1106]: info: Preload queue cleared May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::volumioReplaceandPlayItems May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::ClearQueue May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::stop May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::setConsumeUpdateService undefined May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::stPlaybackTimer May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::updateTrackBlock May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrackBlock May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 28 May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::serviceStop May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 28 May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::serviceStop May 18 00:48:40 tinkermio volumio[1106]: info: [1747496920058] ControllerVolusonic::stop May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::stop May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand stop May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::clearPlayQueue May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::saveQueue May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushQueue May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::addQueueItems May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::addQueueItems May 18 00:48:40 tinkermio volumio[1106]: info: Preload queue cleared May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/2ce718c0ef59926c93365761f39a902a May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/2ce718c0ef59926c93365761f39a902a in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/c06061e8d3eb7604a0d2037fc3ac173e May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/c06061e8d3eb7604a0d2037fc3ac173e in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/ebc8b4ae23002aebba1f196768e69e43 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/ebc8b4ae23002aebba1f196768e69e43 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/96440384d03750fbc877f202e85dca46 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/96440384d03750fbc877f202e85dca46 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/9a004e57c6867c7c8b388b88afc0b8ac May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/9a004e57c6867c7c8b388b88afc0b8ac in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/1f18218db23b069b39d539f163ee7422 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/1f18218db23b069b39d539f163ee7422 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/cb77e0ae6c08410d5537d830fff1faf5 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/cb77e0ae6c08410d5537d830fff1faf5 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/e77512eff976e47deda27c595824f8e3 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/e77512eff976e47deda27c595824f8e3 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/2103fb98c48b1bbeb8345fb62bf041cf May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/2103fb98c48b1bbeb8345fb62bf041cf in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/013168940c4025725f2f483465ff47c3 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/013168940c4025725f2f483465ff47c3 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/c42a03e1d6f3599426f6b7daf5f1c576 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/c42a03e1d6f3599426f6b7daf5f1c576 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/8b886c2c6cb7da379c61902271039f86 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/8b886c2c6cb7da379c61902271039f86 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/fa6cd6b9f58647eea462b12d6f1d697a May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/fa6cd6b9f58647eea462b12d6f1d697a in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/0fcd1a210760d0c42814e07069cc8125 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/0fcd1a210760d0c42814e07069cc8125 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/f4663ae0fe524462e847d16519a6e95d May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/f4663ae0fe524462e847d16519a6e95d in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/e913a5323b94183c48653b5074d02471 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/e913a5323b94183c48653b5074d02471 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/1e7f7145377c831c0b585e9cf34e5321 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/1e7f7145377c831c0b585e9cf34e5321 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/dd99e27c83dff31bc8d5f2597f2eb598 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/dd99e27c83dff31bc8d5f2597f2eb598 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/815ec6bef025225206eb489a01e41cb3 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/815ec6bef025225206eb489a01e41cb3 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/efb03a53d0448b1b54390b1b546b96f0 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/efb03a53d0448b1b54390b1b546b96f0 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushQueue May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::saveQueue May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::updateTrackBlock May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrackBlock May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPlay May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::play index 19 May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::setConsumeUpdateService undefined May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::addQueueItems May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::addQueueItems May 18 00:48:40 tinkermio volumio[1106]: info: Preload queue cleared May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/83be64d00bf5cd2b039bd9360ca97967 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/83be64d00bf5cd2b039bd9360ca97967 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/b3b760df0087ef56ff427d250308234e May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/b3b760df0087ef56ff427d250308234e in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/bb3a12cefa85f501907a2ac35e0c03e7 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/bb3a12cefa85f501907a2ac35e0c03e7 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/cbd78cf846edfefe09824612ea6cade4 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/cbd78cf846edfefe09824612ea6cade4 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/5c6ee8de0af0e319681a19318192f809 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/5c6ee8de0af0e319681a19318192f809 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/023bf50e7d3df3b2ac40f418ece535c2 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/023bf50e7d3df3b2ac40f418ece535c2 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/b2ce8c0c69b7b0f31bc1787d8b6fa62b May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/b2ce8c0c69b7b0f31bc1787d8b6fa62b in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/20142d28200d30dad28d4dfedae636a5 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/20142d28200d30dad28d4dfedae636a5 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/42e84be71cde2949c70f059228572983 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/42e84be71cde2949c70f059228572983 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/7916b0df084a3628dedb0a92e5251934 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/7916b0df084a3628dedb0a92e5251934 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/efa84f42f99be327db6b4fb32dc7ef87 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/efa84f42f99be327db6b4fb32dc7ef87 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/18148e0615a81b1a16c602228ea45273 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/18148e0615a81b1a16c602228ea45273 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/4958b047e7bf4ecf8b9b786f25c4d76c May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/4958b047e7bf4ecf8b9b786f25c4d76c in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/fc8fa83ede5c17788f9c8f080df554cd May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/fc8fa83ede5c17788f9c8f080df554cd in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/b9df49469b391374e8ebdb1491f8fcf9 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/b9df49469b391374e8ebdb1491f8fcf9 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/b0584d87d69ee435945362c17af563fe May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/b0584d87d69ee435945362c17af563fe in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/82573626984e800d835e5e5eaaa027cb May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/82573626984e800d835e5e5eaaa027cb in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/a53fa7f3c2fde3526f0fdf1bc86c8193 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/a53fa7f3c2fde3526f0fdf1bc86c8193 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/1a780480ffc4c51d3f0f649a9c9ae0a6 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/1a780480ffc4c51d3f0f649a9c9ae0a6 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/4a076692ae59e81227fba32c37d62446 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/4a076692ae59e81227fba32c37d62446 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/a92f0cb116cf74e763aee897b743c733 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/a92f0cb116cf74e763aee897b743c733 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/0437f90a73c2003ad73733062f551cc5 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/0437f90a73c2003ad73733062f551cc5 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/a18d9ee7833b85e17635014868f7decf May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/a18d9ee7833b85e17635014868f7decf in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/1516fe250651c09c1860c9a757481e32 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/1516fe250651c09c1860c9a757481e32 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/8d848bbeb6dfd103871a380c7ec61244 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/8d848bbeb6dfd103871a380c7ec61244 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/daab76551ee3315ec4cc21260d46af91 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/daab76551ee3315ec4cc21260d46af91 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/197adff011b97d0fc17b6512748b8eeb May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/197adff011b97d0fc17b6512748b8eeb in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/ea3d2b05488f9e70a75006ca514013e6 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/ea3d2b05488f9e70a75006ca514013e6 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/1b61c8094bee8eeefe6ae59c11aeed4b May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/1b61c8094bee8eeefe6ae59c11aeed4b in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/00e859881feb9ae06b5b792a135b63ec May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/00e859881feb9ae06b5b792a135b63ec in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/bd3a23f6b9a427460e801413db3a9960 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/bd3a23f6b9a427460e801413db3a9960 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/cdf3f6b399247913e175d78c4ea24c30 May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/cdf3f6b399247913e175d78c4ea24c30 in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/2a579c9bff879cf367201ceb1042d62b May 18 00:48:40 tinkermio volumio[1106]: info: Exploding uri volusonic/track/2a579c9bff879cf367201ceb1042d62b in service volusonic May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::stop May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::setConsumeUpdateService undefined May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::play index undefined May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::setConsumeUpdateService undefined May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::startPlaybackTimer May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: [1747496920101] ControllerVolusonic::clearAddPlayTrack May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand stop May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushQueue May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::saveQueue May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::updateTrackBlock May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrackBlock May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: SPOTIFY VOLUME 13 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: VOLUMIO VOLUME 14 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: DELTA VOLUME ENOUGH: false May 18 00:48:40 tinkermio volumio[1106]: info: [1747496920132] ControllerVolusonic: MPD player state update May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand stop took 75 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand stop took 32 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand clear May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:40 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand status took 6 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand status took 5 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand status took 5 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand clear took 4 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand status took 4 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand status took 3 milliseconds May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand load "https://znd.servebeer.com/navid/rest/stream.view?id=efb03a53d0448b1b54390b1b546b96f0&format=raw&u=tmtm&t=aa8135645674db49f5ff033094ae4687&s=4f4sw&v=1.10.2&f=json&c=volusonic" May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 15ms May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 15ms May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:40 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:40 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:40 tinkermio volumio[1106]: error: updateQueue error: null May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 24ms May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 22 milliseconds May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:40 tinkermio volumio[1106]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 31ms May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: SPOTIFY VOLUME 13 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: VOLUMIO VOLUME 14 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: DELTA VOLUME ENOUGH: false May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: SPOTIFY VOLUME 13 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: VOLUMIO VOLUME 14 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: DELTA VOLUME ENOUGH: false May 18 00:48:40 tinkermio volumio[1106]: error: updateQueue error: null May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand add "https://znd.servebeer.com/navid/rest/stream.view?id=efb03a53d0448b1b54390b1b546b96f0&format=raw&u=tmtm&t=aa8135645674db49f5ff033094ae4687&s=4f4sw&v=1.10.2&f=json&c=volusonic" May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 28ms May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:40 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand add "https://znd.servebeer.com/navid/rest/stream.view?id=efb03a53d0448b1b54390b1b546b96f0&format=raw&u=tmtm&t=aa8135645674db49f5ff033094ae4687&s=4f4sw&v=1.10.2&f=json&c=volusonic" took 2 milliseconds May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand play May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:40 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:40 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 4ms May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand play took 3 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 3ms May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 2ms May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand status took 1 milliseconds May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 1 milliseconds May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:40 tinkermio volumio[1106]: info: [1747496920188] ControllerVolusonic::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.view?id=efb03a53d0448b1b54390b1b546b96f0&format=raw&u=tmtm&t=aa8135645674db49f5ff033094ae4687&s=4f4sw&v=1.10.2&f=json&c=volusonic","artist":null,"album":null,"uri":"https://znd.servebeer.com/navid/rest/stream.view?id=efb03a53d0448b1b54390b1b546b96f0&format=raw&u=tmtm&t=aa8135645674db49f5ff033094ae4687&s=4f4sw&v=1.10.2&f=json&c=volusonic","trackType":""} May 18 00:48:40 tinkermio volumio[1106]: verbose: CURRENT POSITION 19 May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::syncState stateService play May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::syncState currentStatus stop May 18 00:48:40 tinkermio volumio[1106]: info: [1747496920467] ControllerVolusonic: MPD player state update May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand status took 54 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand status took 54 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand status took 54 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand status took 53 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand status took 3 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 3 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 3 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 2 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 3 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand status took 2 milliseconds May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: [1747496920528] ControllerVolusonic::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":113,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.view?id=efb03a53d0448b1b54390b1b546b96f0&format=raw&u=tmtm&t=aa8135645674db49f5ff033094ae4687&s=4f4sw&v=1.10.2&f=json&c=volusonic","artist":null,"album":null,"uri":"https://znd.servebeer.com/navid/rest/stream.view?id=efb03a53d0448b1b54390b1b546b96f0&format=raw&u=tmtm&t=aa8135645674db49f5ff033094ae4687&s=4f4sw&v=1.10.2&f=json&c=volusonic","trackType":""} May 18 00:48:40 tinkermio volumio[1106]: verbose: CURRENT POSITION 19 May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::syncState stateService play May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::syncState currentStatus play May 18 00:48:40 tinkermio volumio[1106]: info: Received an update from plugin. extracting info from payload May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushState May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 77ms May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 76ms May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 77ms May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 19 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 19 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 19 milliseconds May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 32ms May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 29ms May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 29ms May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::volumioGetQueue May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::getQueue May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getQueue May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: SPOTIFY VOLUME 13 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: VOLUMIO VOLUME 14 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: DELTA VOLUME ENOUGH: false May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: SPOTIFY VOLUME 13 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: VOLUMIO VOLUME 14 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: DELTA VOLUME ENOUGH: false May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:40 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:40 tinkermio volumio[1106]: info: [1747496920566] ControllerVolusonic: MPD player state update May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:40 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:40 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:40 tinkermio volumio[1106]: info: May 18 00:48:40 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand status took 3 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 3ms May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand status took 2 milliseconds May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 5ms May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand status took 4 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 4ms May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand status took 4 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 3 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 3 milliseconds May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: [1747496920574] ControllerVolusonic::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":113,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"893 Kbps","isStreaming":false,"title":"レッドコメット","artist":"横田真人","album":"SUPER MARIO GALAXY ORIGINAL SOUND TRACK Platinum Version Disk2","uri":"https://znd.servebeer.com/navid/rest/stream.view?id=efb03a53d0448b1b54390b1b546b96f0&format=raw&u=tmtm&t=aa8135645674db49f5ff033094ae4687&s=4f4sw&v=1.10.2&f=json&c=volusonic","trackType":""} May 18 00:48:40 tinkermio volumio[1106]: verbose: CURRENT POSITION 19 May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::syncState stateService play May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::syncState currentStatus play May 18 00:48:40 tinkermio volumio[1106]: info: Received an update from plugin. extracting info from payload May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreStateMachine::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushState May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 22ms May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 16 milliseconds May 18 00:48:40 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 16 milliseconds May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:40 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:40 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:40 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:40 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:40 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 23ms May 18 00:48:40 tinkermio volumio[1106]: info: ------------------------------ 22ms May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: SPOTIFY VOLUME 13 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: VOLUMIO VOLUME 14 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: DELTA VOLUME ENOUGH: false May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: SPOTIFY VOLUME 13 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: VOLUMIO VOLUME 14 May 18 00:48:40 tinkermio volumio[1106]: SPOTIFY: DELTA VOLUME ENOUGH: false May 18 00:48:53 tinkermio volumio[1106]: info: Preload queue cleared May 18 00:48:53 tinkermio volumio[1106]: info: CoreCommandRouter::volumioReplaceandPlayItems May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::ClearQueue May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::stop May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::setConsumeUpdateService undefined May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::stPlaybackTimer May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::updateTrackBlock May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::getTrackBlock May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::pushState May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:53 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 00:48:53 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushState May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::serviceStop May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 19 May 18 00:48:53 tinkermio volumio[1106]: info: CoreCommandRouter::serviceStop May 18 00:48:53 tinkermio volumio[1106]: info: [1747496933554] ControllerVolusonic::stop May 18 00:48:53 tinkermio volumio[1106]: info: ControllerMpd::stop May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand stop May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::clearPlayQueue May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::saveQueue May 18 00:48:53 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushQueue May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::addQueueItems May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::addQueueItems May 18 00:48:53 tinkermio volumio[1106]: info: Preload queue cleared May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/2ce718c0ef59926c93365761f39a902a May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/2ce718c0ef59926c93365761f39a902a in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/c06061e8d3eb7604a0d2037fc3ac173e May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/c06061e8d3eb7604a0d2037fc3ac173e in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/ebc8b4ae23002aebba1f196768e69e43 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/ebc8b4ae23002aebba1f196768e69e43 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/96440384d03750fbc877f202e85dca46 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/96440384d03750fbc877f202e85dca46 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/9a004e57c6867c7c8b388b88afc0b8ac May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/9a004e57c6867c7c8b388b88afc0b8ac in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/1f18218db23b069b39d539f163ee7422 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/1f18218db23b069b39d539f163ee7422 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/cb77e0ae6c08410d5537d830fff1faf5 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/cb77e0ae6c08410d5537d830fff1faf5 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/e77512eff976e47deda27c595824f8e3 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/e77512eff976e47deda27c595824f8e3 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/2103fb98c48b1bbeb8345fb62bf041cf May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/2103fb98c48b1bbeb8345fb62bf041cf in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/013168940c4025725f2f483465ff47c3 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/013168940c4025725f2f483465ff47c3 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/c42a03e1d6f3599426f6b7daf5f1c576 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/c42a03e1d6f3599426f6b7daf5f1c576 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/8b886c2c6cb7da379c61902271039f86 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/8b886c2c6cb7da379c61902271039f86 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/fa6cd6b9f58647eea462b12d6f1d697a May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/fa6cd6b9f58647eea462b12d6f1d697a in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/0fcd1a210760d0c42814e07069cc8125 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/0fcd1a210760d0c42814e07069cc8125 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/f4663ae0fe524462e847d16519a6e95d May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/f4663ae0fe524462e847d16519a6e95d in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/e913a5323b94183c48653b5074d02471 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/e913a5323b94183c48653b5074d02471 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/1e7f7145377c831c0b585e9cf34e5321 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/1e7f7145377c831c0b585e9cf34e5321 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushQueue May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::saveQueue May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::updateTrackBlock May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::getTrackBlock May 18 00:48:53 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPlay May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::play index 16 May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::setConsumeUpdateService undefined May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::addQueueItems May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::addQueueItems May 18 00:48:53 tinkermio volumio[1106]: info: Preload queue cleared May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/dd99e27c83dff31bc8d5f2597f2eb598 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/dd99e27c83dff31bc8d5f2597f2eb598 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/815ec6bef025225206eb489a01e41cb3 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/815ec6bef025225206eb489a01e41cb3 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/efb03a53d0448b1b54390b1b546b96f0 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/efb03a53d0448b1b54390b1b546b96f0 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/83be64d00bf5cd2b039bd9360ca97967 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/83be64d00bf5cd2b039bd9360ca97967 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/b3b760df0087ef56ff427d250308234e May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/b3b760df0087ef56ff427d250308234e in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/bb3a12cefa85f501907a2ac35e0c03e7 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/bb3a12cefa85f501907a2ac35e0c03e7 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/cbd78cf846edfefe09824612ea6cade4 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/cbd78cf846edfefe09824612ea6cade4 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/5c6ee8de0af0e319681a19318192f809 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/5c6ee8de0af0e319681a19318192f809 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/023bf50e7d3df3b2ac40f418ece535c2 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/023bf50e7d3df3b2ac40f418ece535c2 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/b2ce8c0c69b7b0f31bc1787d8b6fa62b May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/b2ce8c0c69b7b0f31bc1787d8b6fa62b in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/20142d28200d30dad28d4dfedae636a5 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/20142d28200d30dad28d4dfedae636a5 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/42e84be71cde2949c70f059228572983 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/42e84be71cde2949c70f059228572983 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/7916b0df084a3628dedb0a92e5251934 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/7916b0df084a3628dedb0a92e5251934 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/efa84f42f99be327db6b4fb32dc7ef87 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/efa84f42f99be327db6b4fb32dc7ef87 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/18148e0615a81b1a16c602228ea45273 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/18148e0615a81b1a16c602228ea45273 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/4958b047e7bf4ecf8b9b786f25c4d76c May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/4958b047e7bf4ecf8b9b786f25c4d76c in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/fc8fa83ede5c17788f9c8f080df554cd May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/fc8fa83ede5c17788f9c8f080df554cd in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/b9df49469b391374e8ebdb1491f8fcf9 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/b9df49469b391374e8ebdb1491f8fcf9 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/b0584d87d69ee435945362c17af563fe May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/b0584d87d69ee435945362c17af563fe in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/82573626984e800d835e5e5eaaa027cb May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/82573626984e800d835e5e5eaaa027cb in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/a53fa7f3c2fde3526f0fdf1bc86c8193 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/a53fa7f3c2fde3526f0fdf1bc86c8193 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/1a780480ffc4c51d3f0f649a9c9ae0a6 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/1a780480ffc4c51d3f0f649a9c9ae0a6 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/4a076692ae59e81227fba32c37d62446 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/4a076692ae59e81227fba32c37d62446 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/a92f0cb116cf74e763aee897b743c733 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/a92f0cb116cf74e763aee897b743c733 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/0437f90a73c2003ad73733062f551cc5 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/0437f90a73c2003ad73733062f551cc5 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/a18d9ee7833b85e17635014868f7decf May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/a18d9ee7833b85e17635014868f7decf in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/1516fe250651c09c1860c9a757481e32 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/1516fe250651c09c1860c9a757481e32 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/8d848bbeb6dfd103871a380c7ec61244 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/8d848bbeb6dfd103871a380c7ec61244 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/daab76551ee3315ec4cc21260d46af91 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/daab76551ee3315ec4cc21260d46af91 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/197adff011b97d0fc17b6512748b8eeb May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/197adff011b97d0fc17b6512748b8eeb in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/ea3d2b05488f9e70a75006ca514013e6 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/ea3d2b05488f9e70a75006ca514013e6 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/1b61c8094bee8eeefe6ae59c11aeed4b May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/1b61c8094bee8eeefe6ae59c11aeed4b in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/00e859881feb9ae06b5b792a135b63ec May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/00e859881feb9ae06b5b792a135b63ec in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/bd3a23f6b9a427460e801413db3a9960 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/bd3a23f6b9a427460e801413db3a9960 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/cdf3f6b399247913e175d78c4ea24c30 May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/cdf3f6b399247913e175d78c4ea24c30 in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: Adding Item to queue: volusonic/track/2a579c9bff879cf367201ceb1042d62b May 18 00:48:53 tinkermio volumio[1106]: info: Exploding uri volusonic/track/2a579c9bff879cf367201ceb1042d62b in service volusonic May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::stop May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::setConsumeUpdateService undefined May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::play index undefined May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::setConsumeUpdateService undefined May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::startPlaybackTimer May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:53 tinkermio volumio[1106]: info: [1747496933589] ControllerVolusonic::clearAddPlayTrack May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand stop May 18 00:48:53 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushQueue May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::saveQueue May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::updateTrackBlock May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::getTrackBlock May 18 00:48:53 tinkermio volumio[1106]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 May 18 00:48:53 tinkermio volumio[1106]: SPOTIFY: SPOTIFY VOLUME 13 May 18 00:48:53 tinkermio volumio[1106]: SPOTIFY: VOLUMIO VOLUME 14 May 18 00:48:53 tinkermio volumio[1106]: SPOTIFY: DELTA VOLUME ENOUGH: false May 18 00:48:53 tinkermio volumio[1106]: info: [1747496933621] ControllerVolusonic: MPD player state update May 18 00:48:53 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:53 tinkermio volumio[1106]: info: May 18 00:48:53 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:53 tinkermio volumio[1106]: info: sendMpdCommand stop took 68 milliseconds May 18 00:48:53 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:53 tinkermio volumio[1106]: info: sendMpdCommand stop took 33 milliseconds May 18 00:48:53 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand clear May 18 00:48:53 tinkermio volumio[1106]: info: May 18 00:48:53 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:53 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:53 tinkermio volumio[1106]: info: May 18 00:48:53 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:53 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:53 tinkermio volumio[1106]: info: May 18 00:48:53 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:53 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:53 tinkermio volumio[1106]: info: sendMpdCommand status took 6 milliseconds May 18 00:48:53 tinkermio volumio[1106]: info: sendMpdCommand status took 6 milliseconds May 18 00:48:53 tinkermio volumio[1106]: info: sendMpdCommand status took 5 milliseconds May 18 00:48:53 tinkermio volumio[1106]: info: sendMpdCommand clear took 5 milliseconds May 18 00:48:53 tinkermio volumio[1106]: info: sendMpdCommand status took 5 milliseconds May 18 00:48:53 tinkermio volumio[1106]: info: sendMpdCommand status took 5 milliseconds May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand load "https://znd.servebeer.com/navid/rest/stream.view?id=1e7f7145377c831c0b585e9cf34e5321&format=raw&u=tmtm&t=aa8135645674db49f5ff033094ae4687&s=4f4sw&v=1.10.2&f=json&c=volusonic" May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:53 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:53 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::pushState May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:53 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 00:48:53 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushState May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:53 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:53 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:53 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::pushState May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:53 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushState May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:53 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:53 tinkermio volumio[1106]: info: ------------------------------ 17ms May 18 00:48:53 tinkermio volumio[1106]: info: ------------------------------ 16ms May 18 00:48:53 tinkermio volumio[1106]: info: May 18 00:48:53 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:53 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:53 tinkermio volumio[1106]: info: May 18 00:48:53 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:53 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:53 tinkermio volumio[1106]: error: updateQueue error: null May 18 00:48:53 tinkermio volumio[1106]: info: ------------------------------ 14ms May 18 00:48:53 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 13 milliseconds May 18 00:48:53 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 14 milliseconds May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:53 tinkermio volumio[1106]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined May 18 00:48:53 tinkermio volumio[1106]: info: ------------------------------ 23ms May 18 00:48:53 tinkermio volumio[1106]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 May 18 00:48:53 tinkermio volumio[1106]: SPOTIFY: SPOTIFY VOLUME 13 May 18 00:48:53 tinkermio volumio[1106]: SPOTIFY: VOLUMIO VOLUME 14 May 18 00:48:53 tinkermio volumio[1106]: SPOTIFY: DELTA VOLUME ENOUGH: false May 18 00:48:53 tinkermio volumio[1106]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 May 18 00:48:53 tinkermio volumio[1106]: SPOTIFY: SPOTIFY VOLUME 13 May 18 00:48:53 tinkermio volumio[1106]: SPOTIFY: VOLUMIO VOLUME 14 May 18 00:48:53 tinkermio volumio[1106]: SPOTIFY: DELTA VOLUME ENOUGH: false May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand add "https://znd.servebeer.com/navid/rest/stream.view?id=1e7f7145377c831c0b585e9cf34e5321&format=raw&u=tmtm&t=aa8135645674db49f5ff033094ae4687&s=4f4sw&v=1.10.2&f=json&c=volusonic" May 18 00:48:53 tinkermio volumio[1106]: error: updateQueue error: null May 18 00:48:53 tinkermio volumio[1106]: error: updateQueue error: null May 18 00:48:53 tinkermio volumio[1106]: info: May 18 00:48:53 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:53 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:53 tinkermio volumio[1106]: info: ------------------------------ 49ms May 18 00:48:53 tinkermio volumio[1106]: info: ------------------------------ 49ms May 18 00:48:53 tinkermio volumio[1106]: info: sendMpdCommand add "https://znd.servebeer.com/navid/rest/stream.view?id=1e7f7145377c831c0b585e9cf34e5321&format=raw&u=tmtm&t=aa8135645674db49f5ff033094ae4687&s=4f4sw&v=1.10.2&f=json&c=volusonic" took 1 milliseconds May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand play May 18 00:48:53 tinkermio volumio[1106]: info: May 18 00:48:53 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:53 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:53 tinkermio volumio[1106]: info: May 18 00:48:53 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:53 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:53 tinkermio volumio[1106]: info: ------------------------------ 3ms May 18 00:48:53 tinkermio volumio[1106]: info: sendMpdCommand play took 3 milliseconds May 18 00:48:53 tinkermio volumio[1106]: info: ------------------------------ 2ms May 18 00:48:53 tinkermio volumio[1106]: info: ------------------------------ 1ms May 18 00:48:53 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:53 tinkermio volumio[1106]: info: sendMpdCommand status took 0 milliseconds May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:53 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 0 milliseconds May 18 00:48:53 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:53 tinkermio volumio[1106]: info: [1747496933695] ControllerVolusonic::pushState May 18 00:48:53 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:53 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:53 tinkermio volumio[1106]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.view?id=1e7f7145377c831c0b585e9cf34e5321&format=raw&u=tmtm&t=aa8135645674db49f5ff033094ae4687&s=4f4sw&v=1.10.2&f=json&c=volusonic","artist":null,"album":null,"uri":"https://znd.servebeer.com/navid/rest/stream.view?id=1e7f7145377c831c0b585e9cf34e5321&format=raw&u=tmtm&t=aa8135645674db49f5ff033094ae4687&s=4f4sw&v=1.10.2&f=json&c=volusonic","trackType":""} May 18 00:48:53 tinkermio volumio[1106]: verbose: CURRENT POSITION 16 May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::syncState stateService play May 18 00:48:53 tinkermio volumio[1106]: info: CoreStateMachine::syncState currentStatus stop May 18 00:48:54 tinkermio volumio[1106]: info: [1747496934008] ControllerVolusonic: MPD player state update May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:54 tinkermio volumio[1106]: info: May 18 00:48:54 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:54 tinkermio volumio[1106]: info: May 18 00:48:54 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:54 tinkermio volumio[1106]: info: May 18 00:48:54 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:54 tinkermio volumio[1106]: info: May 18 00:48:54 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand status took 53 milliseconds May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand status took 52 milliseconds May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand status took 54 milliseconds May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand status took 53 milliseconds May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand status took 1 milliseconds May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 1 milliseconds May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 1 milliseconds May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: info: [1747496934065] ControllerVolusonic::pushState May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":91,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"stream.view?id=1e7f7145377c831c0b585e9cf34e5321&format=raw&u=tmtm&t=aa8135645674db49f5ff033094ae4687&s=4f4sw&v=1.10.2&f=json&c=volusonic","artist":null,"album":null,"uri":"https://znd.servebeer.com/navid/rest/stream.view?id=1e7f7145377c831c0b585e9cf34e5321&format=raw&u=tmtm&t=aa8135645674db49f5ff033094ae4687&s=4f4sw&v=1.10.2&f=json&c=volusonic","trackType":""} May 18 00:48:54 tinkermio volumio[1106]: verbose: CURRENT POSITION 16 May 18 00:48:54 tinkermio volumio[1106]: info: CoreStateMachine::syncState stateService play May 18 00:48:54 tinkermio volumio[1106]: info: CoreStateMachine::syncState currentStatus play May 18 00:48:54 tinkermio volumio[1106]: info: Received an update from plugin. extracting info from payload May 18 00:48:54 tinkermio volumio[1106]: info: CoreStateMachine::pushState May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushState May 18 00:48:54 tinkermio volumio[1106]: info: CoreStateMachine::pushState May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushState May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:54 tinkermio volumio[1106]: info: ------------------------------ 72ms May 18 00:48:54 tinkermio volumio[1106]: info: May 18 00:48:54 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:54 tinkermio volumio[1106]: info: May 18 00:48:54 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 18 milliseconds May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 18 milliseconds May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 18 milliseconds May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand status took 1 milliseconds May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand status took 1 milliseconds May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:54 tinkermio volumio[1106]: info: ------------------------------ 75ms May 18 00:48:54 tinkermio volumio[1106]: info: ------------------------------ 24ms May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::volumioGetQueue May 18 00:48:54 tinkermio volumio[1106]: info: CoreStateMachine::getQueue May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getQueue May 18 00:48:54 tinkermio volumio[1106]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 May 18 00:48:54 tinkermio volumio[1106]: SPOTIFY: SPOTIFY VOLUME 13 May 18 00:48:54 tinkermio volumio[1106]: SPOTIFY: VOLUMIO VOLUME 14 May 18 00:48:54 tinkermio volumio[1106]: SPOTIFY: DELTA VOLUME ENOUGH: false May 18 00:48:54 tinkermio volumio[1106]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 May 18 00:48:54 tinkermio volumio[1106]: SPOTIFY: SPOTIFY VOLUME 13 May 18 00:48:54 tinkermio volumio[1106]: SPOTIFY: VOLUMIO VOLUME 14 May 18 00:48:54 tinkermio volumio[1106]: SPOTIFY: DELTA VOLUME ENOUGH: false May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 11 milliseconds May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 11 milliseconds May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:54 tinkermio volumio[1106]: info: ------------------------------ 15ms May 18 00:48:54 tinkermio volumio[1106]: info: May 18 00:48:54 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:54 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:54 tinkermio volumio[1106]: info: [1747496934135] ControllerVolusonic: MPD player state update May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:54 tinkermio volumio[1106]: info: May 18 00:48:54 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:54 tinkermio volumio[1106]: info: May 18 00:48:54 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:54 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:54 tinkermio volumio[1106]: info: May 18 00:48:54 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand status took 3 milliseconds May 18 00:48:54 tinkermio volumio[1106]: info: ------------------------------ 3ms May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand status took 2 milliseconds May 18 00:48:54 tinkermio volumio[1106]: info: ------------------------------ 2ms May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand status took 1 milliseconds May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:54 tinkermio volumio[1106]: info: May 18 00:48:54 tinkermio volumio[1106]: ---------------------------- MPD announces system playlist update May 18 00:48:54 tinkermio volumio[1106]: info: Ignoring MPD Status Update May 18 00:48:54 tinkermio volumio[1106]: info: May 18 00:48:54 tinkermio volumio[1106]: ---------------------------- MPD announces state update: player May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::getState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand status May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 2 milliseconds May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 2 milliseconds May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 2 milliseconds May 18 00:48:54 tinkermio volumio[1106]: info: ------------------------------ 2ms May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand status took 1 milliseconds May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseState May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: info: [1747496934142] ControllerVolusonic::pushState May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":91,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"729 Kbps","isStreaming":false,"title":"メガレッグ","artist":"横田真人","album":"SUPER MARIO GALAXY ORIGINAL SOUND TRACK Platinum Version Disk2","uri":"https://znd.servebeer.com/navid/rest/stream.view?id=1e7f7145377c831c0b585e9cf34e5321&format=raw&u=tmtm&t=aa8135645674db49f5ff033094ae4687&s=4f4sw&v=1.10.2&f=json&c=volusonic","trackType":""} May 18 00:48:54 tinkermio volumio[1106]: verbose: CURRENT POSITION 16 May 18 00:48:54 tinkermio volumio[1106]: info: CoreStateMachine::syncState stateService play May 18 00:48:54 tinkermio volumio[1106]: info: CoreStateMachine::syncState currentStatus play May 18 00:48:54 tinkermio volumio[1106]: info: Received an update from plugin. extracting info from payload May 18 00:48:54 tinkermio volumio[1106]: info: CoreStateMachine::pushState May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushState May 18 00:48:54 tinkermio volumio[1106]: info: CoreStateMachine::pushState May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::volumioPushState May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:54 tinkermio volumio[1106]: info: ------------------------------ 19ms May 18 00:48:54 tinkermio volumio[1106]: info: ------------------------------ 18ms May 18 00:48:54 tinkermio volumio[1106]: info: sendMpdCommand playlistinfo took 15 milliseconds May 18 00:48:54 tinkermio volumio[1106]: verbose: ControllerMpd::parseTrackInfo May 18 00:48:54 tinkermio volumio[1106]: info: ControllerMpd::pushState May 18 00:48:54 tinkermio volumio[1106]: info: CoreCommandRouter::servicePushState May 18 00:48:54 tinkermio volumio[1106]: info: CorePlayQueue::getTrack 16 May 18 00:48:54 tinkermio volumio[1106]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current volusonic Received mpd May 18 00:48:54 tinkermio volumio[1106]: info: ------------------------------ 20ms May 18 00:48:54 tinkermio volumio[1106]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 May 18 00:48:54 tinkermio volumio[1106]: SPOTIFY: SPOTIFY VOLUME 13 May 18 00:48:54 tinkermio volumio[1106]: SPOTIFY: VOLUMIO VOLUME 14 May 18 00:48:54 tinkermio volumio[1106]: SPOTIFY: DELTA VOLUME ENOUGH: false May 18 00:48:54 tinkermio volumio[1106]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 May 18 00:48:54 tinkermio volumio[1106]: SPOTIFY: SPOTIFY VOLUME 13 May 18 00:48:54 tinkermio volumio[1106]: SPOTIFY: VOLUMIO VOLUME 14 May 18 00:48:54 tinkermio volumio[1106]: SPOTIFY: DELTA VOLUME ENOUGH: false May 18 00:48:58 tinkermio volumio[1106]: info: Adding volusonic/track/e913a5323b94183c48653b5074d02471 to favourites with specific volusonic method May 18 00:48:58 tinkermio volumio[1106]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 18 00:48:58 tinkermio volumio[1106]: TypeError: Cannot read property 'then' of undefined May 18 00:48:58 tinkermio volumio[1106]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:679:20) May 18 00:48:58 tinkermio volumio[1106]: at Socket.emit (events.js:400:28) May 18 00:48:58 tinkermio volumio[1106]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 May 18 00:48:58 tinkermio volumio[1106]: at processTicksAndRejections (internal/process/task_queues.js:77:11) May 18 00:48:58 tinkermio volumio[1106]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 18 00:48:58 tinkermio sudo[12127]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-18 00:47 May 18 00:48:58 tinkermio sudo[12127]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 09:53:51 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="53825f995260683aee752aed6b29f24e"