-- Logs begin at Tue 2024-10-29 12:51:51 CET, end at Thu 2024-10-31 12:32:44 CET. -- Oct 31 12:31:04 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 31 12:31:04 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 31 12:31:04 primo volumio[3097]: info: Discovery: Getting this device information Oct 31 12:31:04 primo volumio[3097]: info: CoreCommandRouter::volumioGetState Oct 31 12:31:04 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:04 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 31 12:31:04 primo volumio[3097]: verbose: New Socket.io Connection to 192.168.1.116:3000 from 192.168.1.63 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Oct 31 12:31:04 primo volumio[3097]: info: CoreCommandRouter::volumioGetState Oct 31 12:31:04 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:04 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 31 12:31:04 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 31 12:31:04 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 31 12:31:04 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 31 12:31:04 primo volumio[3097]: info: Discovery: Getting this device information Oct 31 12:31:04 primo volumio[3097]: info: CoreCommandRouter::volumioGetState Oct 31 12:31:04 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:04 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 31 12:31:07 primo sudo[6132]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 31 12:31:07 primo sudo[6132]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 12:31:07 primo sudo[6132]: pam_unix(sudo:session): session closed for user root Oct 31 12:31:07 primo sudo[6136]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 31 12:31:07 primo sudo[6136]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 12:31:07 primo sudo[6136]: pam_unix(sudo:session): session closed for user root Oct 31 12:31:07 primo volumio[3097]: verbose: New Socket.io Connection to 192.168.1.116 from 192.168.1.63 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 8 Oct 31 12:31:07 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 31 12:31:07 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 31 12:31:07 primo sudo[6140]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 31 12:31:07 primo sudo[6140]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 12:31:07 primo sudo[6140]: pam_unix(sudo:session): session closed for user root Oct 31 12:31:07 primo sudo[6144]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 31 12:31:07 primo sudo[6144]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 12:31:07 primo sudo[6144]: pam_unix(sudo:session): session closed for user root Oct 31 12:31:07 primo volumio[3097]: verbose: New Socket.io Connection to 192.168.1.116 from 192.168.1.63 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Engine version: 3 Transport: polling Total Clients: 8 Oct 31 12:31:07 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 31 12:31:07 primo volumio[3097]: info: CoreCommandRouter::volumioGetVisibleSources Oct 31 12:31:07 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 12:31:07 primo volumio[3097]: info: CoreCommandRouter::volumioGetState Oct 31 12:31:07 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:07 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 31 12:31:07 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 31 12:31:07 primo volumio[3097]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Oct 31 12:31:07 primo volumio[3097]: info: Received Get System Info Oct 31 12:31:07 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 31 12:31:07 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 31 12:31:07 primo volumio[3097]: info: Discovery: Getting this device information Oct 31 12:31:07 primo volumio[3097]: info: CoreCommandRouter::volumioGetState Oct 31 12:31:07 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:07 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 31 12:31:07 primo volumio[3097]: info: CoreCommandRouter::volumioGetState Oct 31 12:31:07 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:07 primo volumio[3097]: info: Listing playlists Oct 31 12:31:07 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 31 12:31:07 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 31 12:31:07 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 31 12:31:08 primo volumio[3097]: info: CoreCommandRouter::volumioGetState Oct 31 12:31:08 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:09 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 31 12:31:09 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 31 12:31:09 primo volumio[3097]: info: Received Get System Info Oct 31 12:31:09 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 31 12:31:09 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 31 12:31:09 primo volumio[3097]: info: Discovery: Getting this device information Oct 31 12:31:09 primo volumio[3097]: info: CoreCommandRouter::volumioGetState Oct 31 12:31:09 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:09 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 31 12:31:10 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 31 12:31:10 primo volumio[3097]: info: Received Get System Info Oct 31 12:31:10 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 31 12:31:10 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 31 12:31:10 primo volumio[3097]: info: Discovery: Getting this device information Oct 31 12:31:10 primo volumio[3097]: info: CoreCommandRouter::volumioGetState Oct 31 12:31:10 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:10 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 31 12:31:10 primo volumio[3097]: info: Executing endpoint metavolumio Oct 31 12:31:10 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 12:31:10 primo volumio[3097]: info: Executing endpoint metavolumio Oct 31 12:31:10 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 12:31:10 primo volumio[3097]: info: Executing endpoint metavolumio Oct 31 12:31:10 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 12:31:17 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 31 12:31:17 primo volumio[3097]: error: Failed request for metavolumio API Oct 31 12:31:18 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 107088375 Oct 31 12:31:18 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:18 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/2853581 Oct 31 12:31:18 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:18 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:18 primo volumio[3097]: info: getStreamUrl took 451 milliseconds Oct 31 12:31:18 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=2853581&fmt=6&profile=raw&app_id=539451548&cid=2368250&etsp=1730377878&hmac=bg3c1Bj0H4pXrC1jWS2aQoydGHU Oct 31 12:31:19 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 13143917 Oct 31 12:31:19 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:19 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/2853581 Oct 31 12:31:19 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:19 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:19 primo volumio[3097]: info: getStreamUrl took 646 milliseconds Oct 31 12:31:19 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=2853581&fmt=6&profile=raw&app_id=539451548&cid=2368250&etsp=1730377879&hmac=kRfh1gH2yPznuCcl_h3OIZg2e9E Oct 31 12:31:19 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 13143917 Oct 31 12:31:19 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:19 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/2853581 Oct 31 12:31:19 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:19 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:20 primo volumio[3097]: info: getStreamUrl took 489 milliseconds Oct 31 12:31:20 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=2853581&fmt=6&profile=raw&app_id=539451548&cid=2368250&etsp=1730377880&hmac=cIMU86pu8CYcoRvg6xeBHy6HFGU Oct 31 12:31:20 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 13143917 Oct 31 12:31:20 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:20 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/2853581 Oct 31 12:31:20 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:20 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:21 primo volumio[3097]: info: getStreamUrl took 742 milliseconds Oct 31 12:31:21 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=2853581&fmt=6&profile=raw&app_id=539451548&cid=2368250&etsp=1730377880&hmac=cIMU86pu8CYcoRvg6xeBHy6HFGU Oct 31 12:31:21 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 13143917 Oct 31 12:31:21 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:21 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/209616993 Oct 31 12:31:21 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:21 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:21 primo volumio[3097]: info: getStreamUrl took 459 milliseconds Oct 31 12:31:21 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=209616993&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377881&hmac=cSnNr53UmF8v2UNmzGgPYFzPeVE Oct 31 12:31:21 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 107088375 Oct 31 12:31:21 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:21 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/209616993 Oct 31 12:31:21 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:21 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:22 primo volumio[3097]: info: getStreamUrl took 467 milliseconds Oct 31 12:31:22 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=209616993&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377881&hmac=cSnNr53UmF8v2UNmzGgPYFzPeVE Oct 31 12:31:22 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 107088375 Oct 31 12:31:22 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:22 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/209616993 Oct 31 12:31:22 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:22 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:22 primo volumio[3097]: info: getStreamUrl took 539 milliseconds Oct 31 12:31:22 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=209616993&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377882&hmac=l1aKq_sOPlEaHd8ZR4aATfi77UQ Oct 31 12:31:22 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 107088375 Oct 31 12:31:22 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:22 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/209616993 Oct 31 12:31:22 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:22 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:23 primo volumio[3097]: info: getStreamUrl took 514 milliseconds Oct 31 12:31:23 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=209616993&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377883&hmac=Y6b2WBDQS0vwXIp0Jhan3wDOacM Oct 31 12:31:23 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 107088375 Oct 31 12:31:23 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:23 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/209616993 Oct 31 12:31:23 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:23 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:24 primo volumio[3097]: info: getStreamUrl took 775 milliseconds Oct 31 12:31:24 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=209616993&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377883&hmac=Y6b2WBDQS0vwXIp0Jhan3wDOacM Oct 31 12:31:24 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 107088375 Oct 31 12:31:24 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:24 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/209616993 Oct 31 12:31:24 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:24 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:24 primo volumio[3097]: info: getStreamUrl took 692 milliseconds Oct 31 12:31:24 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=209616993&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377884&hmac=hUmdJyoSGAcm9_c8uFXTEahgY4I Oct 31 12:31:24 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 107088375 Oct 31 12:31:24 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:24 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/209616993 Oct 31 12:31:24 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:24 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:25 primo volumio[3097]: info: getStreamUrl took 462 milliseconds Oct 31 12:31:25 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=209616993&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377885&hmac=cBqAzw7ewusGIy9aTLGn7N3qQqc Oct 31 12:31:25 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 107088375 Oct 31 12:31:25 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:25 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/209616993 Oct 31 12:31:25 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:25 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:25 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 31 12:31:25 primo volumio[3097]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 31 12:31:25 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 31 12:31:25 primo volumio[3097]: info: Received Get System Version Oct 31 12:31:25 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 31 12:31:25 primo volumio[3097]: info: Received Get System Info Oct 31 12:31:25 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 31 12:31:25 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 31 12:31:25 primo volumio[3097]: info: Discovery: Getting this device information Oct 31 12:31:25 primo volumio[3097]: info: CoreCommandRouter::volumioGetState Oct 31 12:31:25 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:25 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 31 12:31:25 primo volumio[3097]: info: getStreamUrl took 566 milliseconds Oct 31 12:31:25 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=209616993&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377885&hmac=cBqAzw7ewusGIy9aTLGn7N3qQqc Oct 31 12:31:25 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 107088375 Oct 31 12:31:25 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:26 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/89931433 Oct 31 12:31:26 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:26 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:26 primo volumio[3097]: info: getStreamUrl took 630 milliseconds Oct 31 12:31:26 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=89931433&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377886&hmac=Q82GhKKV8X1ilpwfPo_LumsceDM Oct 31 12:31:27 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 42745083 Oct 31 12:31:27 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:27 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/89931433 Oct 31 12:31:27 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:27 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:27 primo volumio[3097]: info: getStreamUrl took 599 milliseconds Oct 31 12:31:27 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=89931433&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377887&hmac=AYb0BxO1bwCCpufp_UAPZCrj-4c Oct 31 12:31:27 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 42745083 Oct 31 12:31:27 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:27 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/89931433 Oct 31 12:31:27 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:27 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:28 primo volumio[3097]: info: getStreamUrl took 485 milliseconds Oct 31 12:31:28 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=89931433&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377888&hmac=zLegoN9KAepMAUyBQkgsgRNlF_0 Oct 31 12:31:28 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 42745083 Oct 31 12:31:28 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:28 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/89931433 Oct 31 12:31:28 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:28 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:28 primo volumio[3097]: info: getStreamUrl took 568 milliseconds Oct 31 12:31:28 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=89931433&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377888&hmac=zLegoN9KAepMAUyBQkgsgRNlF_0 Oct 31 12:31:28 primo volumio[3097]: info: CoreCommandRouter::volumioPlay Oct 31 12:31:28 primo volumio[3097]: info: CoreStateMachine::play index undefined Oct 31 12:31:28 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 31 12:31:28 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:28 primo volumio[3097]: info: CoreStateMachine::startPlaybackTimer Oct 31 12:31:28 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:28 primo volumio[3097]: info: [1730374288868] ControllerQobuz::clearAddPlayTrack Oct 31 12:31:28 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand stop Oct 31 12:31:28 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 42745083 Oct 31 12:31:28 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:28 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/89931433 Oct 31 12:31:28 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:28 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:29 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 31 12:31:29 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 31 12:31:29 primo volumio[3097]: info: Discovery: Getting this device information Oct 31 12:31:29 primo volumio[3097]: info: CoreCommandRouter::volumioGetState Oct 31 12:31:29 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:29 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 31 12:31:29 primo volumio[3097]: info: getStreamUrl took 448 milliseconds Oct 31 12:31:29 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=89931433&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377889&hmac=7prd2WrGFVV_auaTX3UoCLaObDM Oct 31 12:31:29 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 42745083 Oct 31 12:31:29 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:29 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/209616993 Oct 31 12:31:29 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:29 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:29 primo volumio[3097]: info: getStreamUrl took 448 milliseconds Oct 31 12:31:29 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=209616993&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377889&hmac=4c7xHn0fxoipu5uR21-GHLewi0s Oct 31 12:31:29 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 107088375 Oct 31 12:31:29 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:29 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/209617000 Oct 31 12:31:29 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:29 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:30 primo volumio[3097]: info: getStreamUrl took 452 milliseconds Oct 31 12:31:30 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=209617000&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377890&hmac=8fQfP1SophPhZaMcfzKBOdx7Udk Oct 31 12:31:30 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 178552810 Oct 31 12:31:30 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:30 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/209616993 Oct 31 12:31:30 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:30 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:30 primo volumio[3097]: info: getStreamUrl took 467 milliseconds Oct 31 12:31:30 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=209616993&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377890&hmac=-HnK26j0QS7vZ9R_uQx38Nf7AN4 Oct 31 12:31:31 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 107088375 Oct 31 12:31:31 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:31 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/8020809 Oct 31 12:31:31 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:31 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:31 primo volumio[3097]: info: getStreamUrl took 582 milliseconds Oct 31 12:31:31 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=8020809&fmt=6&profile=raw&app_id=539451548&cid=2368250&etsp=1730377891&hmac=A-hQX_Z40_get-wQVjnBObUa3S8 Oct 31 12:31:32 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 12494418 Oct 31 12:31:32 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:32 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/8020809 Oct 31 12:31:32 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:32 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:32 primo volumio[3097]: info: getStreamUrl took 596 milliseconds Oct 31 12:31:32 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=8020809&fmt=6&profile=raw&app_id=539451548&cid=2368250&etsp=1730377892&hmac=BVFOuzSuxYwCLZwESnqtgbDVF3o Oct 31 12:31:32 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 12494418 Oct 31 12:31:32 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:32 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/8020809 Oct 31 12:31:32 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:32 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:33 primo volumio[3097]: info: getStreamUrl took 571 milliseconds Oct 31 12:31:33 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=8020809&fmt=6&profile=raw&app_id=539451548&cid=2368250&etsp=1730377893&hmac=7btbSlExawZTeru0zCTO7a5hI9Q Oct 31 12:31:33 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 12494418 Oct 31 12:31:33 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:33 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/8020809 Oct 31 12:31:33 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:33 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:35 primo volumio[3097]: info: getStreamUrl took 1601 milliseconds Oct 31 12:31:35 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=8020809&fmt=6&profile=raw&app_id=539451548&cid=2368250&etsp=1730377894&hmac=qDCdId-u6q9i_aieL9C2cjibVno Oct 31 12:31:35 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 12494418 Oct 31 12:31:35 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:35 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/37870896 Oct 31 12:31:35 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:35 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:35 primo volumio[3097]: info: getStreamUrl took 759 milliseconds Oct 31 12:31:35 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=37870896&fmt=27&profile=raw&app_id=539451548&cid=2368250&etsp=1730377895&hmac=VmmOHIFuEfqvJf45ECeekc2nfUA Oct 31 12:31:36 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 125339120 Oct 31 12:31:36 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:36 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/37870896 Oct 31 12:31:36 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:36 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:36 primo volumio[3097]: info: getStreamUrl took 489 milliseconds Oct 31 12:31:36 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=37870896&fmt=27&profile=raw&app_id=539451548&cid=2368250&etsp=1730377896&hmac=H-VB141vdO-PWoInwCIVkxCstCE Oct 31 12:31:36 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 125339120 Oct 31 12:31:36 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:36 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/37870896 Oct 31 12:31:36 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:36 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:37 primo volumio[3097]: info: getStreamUrl took 493 milliseconds Oct 31 12:31:37 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=37870896&fmt=27&profile=raw&app_id=539451548&cid=2368250&etsp=1730377897&hmac=JamjUZabLeL-9Qe_4IDeG9v4b7U Oct 31 12:31:37 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 125339120 Oct 31 12:31:37 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:37 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/13176083 Oct 31 12:31:37 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:37 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:37 primo volumio[3097]: info: getStreamUrl took 469 milliseconds Oct 31 12:31:37 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=13176083&fmt=27&profile=raw&app_id=539451548&cid=2368250&etsp=1730377897&hmac=KUd-nKBOsfVO9Kp5HjqKB_Zi04I Oct 31 12:31:38 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 328084816 Oct 31 12:31:38 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:38 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/13176083 Oct 31 12:31:38 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:38 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:38 primo volumio[3097]: info: getStreamUrl took 477 milliseconds Oct 31 12:31:38 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=13176083&fmt=27&profile=raw&app_id=539451548&cid=2368250&etsp=1730377898&hmac=6VQ-FZ7UmRpAV--gqaj7aruafbA Oct 31 12:31:38 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 328084816 Oct 31 12:31:38 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:38 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/13176083 Oct 31 12:31:38 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:38 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:39 primo volumio[3097]: info: getStreamUrl took 595 milliseconds Oct 31 12:31:39 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=13176083&fmt=27&profile=raw&app_id=539451548&cid=2368250&etsp=1730377899&hmac=8_OZt3n383PNPqRzqxljgVQdUx8 Oct 31 12:31:39 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 328084816 Oct 31 12:31:39 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:39 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/24044960 Oct 31 12:31:39 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:39 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:39 primo volumio[3097]: info: getStreamUrl took 560 milliseconds Oct 31 12:31:39 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=24044960&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377899&hmac=foRPxepTpCHf1nriXgyc7PEGkQg Oct 31 12:31:40 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 286962713 Oct 31 12:31:40 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:40 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/24044960 Oct 31 12:31:40 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:40 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:40 primo volumio[3097]: info: getStreamUrl took 603 milliseconds Oct 31 12:31:40 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=24044960&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377900&hmac=4F2lX3nOFmKNHxa3YzqgJ-Yamno Oct 31 12:31:40 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 286962713 Oct 31 12:31:40 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:40 primo volumio[3097]: Upnp client error: Error: This socket has been ended by the other party Oct 31 12:31:40 primo volumio[3097]: error: updateQueue error: null Oct 31 12:31:40 primo volumio[3097]: error: updateQueue error: null Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/2853581" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/2853581" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/2853581" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/2853581" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/89931433" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/89931433" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/89931433" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/89931433" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/89931433" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209617000" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/8020809" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/8020809" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/8020809" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/8020809" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/37870896" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/37870896" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/37870896" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/13176083" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/13176083" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/13176083" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/24044960" Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/24044960" Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand clear took 60029 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: ------------------------------ 60015ms Oct 31 12:31:40 primo volumio[3097]: info: ------------------------------ 60014ms Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 59347 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand stop took 53775 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand stop took 52826 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand stop took 12012 milliseconds Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/13176083" Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand clear Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand clear Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand clear Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/13176083 Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: Oct 31 12:31:40 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:40 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 86 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 86 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 86 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 86 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 91 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 91 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 91 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 91 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 91 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/2853581" took 92 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/2853581" took 91 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/2853581" took 91 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/2853581" took 92 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 91 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 91 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 92 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 91 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 92 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 94 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 93 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 94 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/89931433" took 94 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/89931433" took 93 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/89931433" took 94 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/89931433" took 95 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/89931433" took 94 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 95 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209617000" took 95 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/209616993" took 95 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/8020809" took 95 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/8020809" took 95 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/8020809" took 95 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/8020809" took 95 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/37870896" took 95 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/37870896" took 95 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/37870896" took 95 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/13176083" took 95 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/13176083" took 95 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/13176083" took 95 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/24044960" took 96 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/24044960" took 95 milliseconds Oct 31 12:31:40 primo volumio[3097]: info: ------------------------------ 112ms Oct 31 12:31:40 primo volumio[3097]: info: ------------------------------ 110ms Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:40 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:40 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:41 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:41 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:41 primo volumio[3097]: info: getStreamUrl took 525 milliseconds Oct 31 12:31:41 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=13176083&fmt=27&profile=raw&app_id=539451548&cid=2368250&etsp=1730377901&hmac=KqfSCuzvOWv8NesFdJncejzkwyI Oct 31 12:31:41 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 328084816 Oct 31 12:31:41 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/13176083" Oct 31 12:31:41 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/209616993 Oct 31 12:31:41 primo volumio[3097]: info: Oct 31 12:31:41 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:41 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:41 primo volumio[3097]: info: Oct 31 12:31:41 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:41 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:41 primo volumio[3097]: error: updateQueue error: null Oct 31 12:31:41 primo volumio[3097]: error: updateQueue error: null Oct 31 12:31:41 primo volumio[3097]: error: updateQueue error: null Oct 31 12:31:41 primo volumio[3097]: error: updateQueue error: null Oct 31 12:31:41 primo volumio[3097]: error: updateQueue error: null Oct 31 12:31:41 primo volumio[3097]: error: updateQueue error: null Oct 31 12:31:41 primo volumio[3097]: error: updateQueue error: null Oct 31 12:31:41 primo volumio[3097]: info: Oct 31 12:31:41 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:41 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:41 primo volumio[3097]: info: Oct 31 12:31:41 primo volumio[3097]: ---------------------------- MPD announces state update: player Oct 31 12:31:41 primo volumio[3097]: info: Oct 31 12:31:41 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:41 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 716 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand clear took 724 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand clear took 724 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand clear took 722 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 721ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 719ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 715ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 714ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 713ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 712ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 711ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 710ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 709ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 709ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 708ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 707ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 706ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 705ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 704ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 703ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 704ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 703ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 702ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 701ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 700ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 699ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 698ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 697ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 697ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 696ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 695ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 694ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 693ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 692ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 691ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 690ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 689ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 688ms Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 659 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 658 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 657 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 657 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 663 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 663 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 663 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 662 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 663 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 662 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 662 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 662 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 655 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 655 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 654 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 654 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 654 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 653 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 653 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 652 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 652 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 652 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 651 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 651 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 650 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 651 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 650 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 650 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 649 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 648 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 644 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 643 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 642 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 641 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand play took 642 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: ControllerMpd::getState Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand status Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/13176083" took 62 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 58ms Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 57ms Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/24044960" Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/24044960" Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:3245?data=qobuz://song/24044960" Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:41 primo volumio[3097]: info: Oct 31 12:31:41 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:41 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/24044960 Oct 31 12:31:41 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:41 primo volumio[3097]: info: Oct 31 12:31:41 primo volumio[3097]: ---------------------------- MPD announces state update: player Oct 31 12:31:41 primo volumio[3097]: info: ControllerMpd::getState Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand status Oct 31 12:31:41 primo volumio[3097]: info: Oct 31 12:31:41 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:41 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:41 primo volumio[3097]: info: Oct 31 12:31:41 primo volumio[3097]: ---------------------------- MPD announces state update: player Oct 31 12:31:41 primo volumio[3097]: info: ControllerMpd::getState Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand status Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 51ms Oct 31 12:31:41 primo volumio[3097]: info: sendMpdCommand status took 11 milliseconds Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 51ms Oct 31 12:31:41 primo volumio[3097]: verbose: ControllerMpd::parseState Oct 31 12:31:41 primo volumio[3097]: info: ControllerMpd::pushState Oct 31 12:31:41 primo volumio[3097]: info: CoreCommandRouter::servicePushState Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:41 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 12:31:41 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:41 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:41 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:41 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:41 primo volumio[3097]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Oct 31 12:31:41 primo volumio[3097]: verbose: CURRENT POSITION 12 Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::syncState stateService stop Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::syncState currentStatus stop Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:41 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:41 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:41 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:41 primo volumio[3097]: info: No code Oct 31 12:31:41 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:41 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:41 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:41 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:41 primo volumio[3097]: info: ------------------------------ 92ms Oct 31 12:31:41 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:41 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:41 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:41 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:41 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:41 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:41 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:41 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:41 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:41 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:41 primo volumio[3097]: info: MCU Signalled Playback Active Oct 31 12:31:42 primo volumio[3097]: info: getStreamUrl took 480 milliseconds Oct 31 12:31:42 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=24044960&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377902&hmac=6zzZfkKw89OMoQWJ05rJJk5qyIc Oct 31 12:31:42 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 286962713 Oct 31 12:31:42 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:42 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/24044960" Oct 31 12:31:42 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/24044960 Oct 31 12:31:42 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:42 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:42 primo volumio[3097]: info: getStreamUrl took 654 milliseconds Oct 31 12:31:42 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=209616993&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377902&hmac=d-iA3JbDunmaM0Tr2ZCdMe-Gk1Q Oct 31 12:31:43 primo volumio[3097]: info: getStreamUrl took 851 milliseconds Oct 31 12:31:43 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=24044960&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377902&hmac=6zzZfkKw89OMoQWJ05rJJk5qyIc Oct 31 12:31:43 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 286962713 Oct 31 12:31:43 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:43 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/24044960 Oct 31 12:31:43 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:43 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:43 primo volumio[3097]: info: Executing endpoint metavolumio Oct 31 12:31:43 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 12:31:43 primo volumio[3097]: info: Executing endpoint metavolumio Oct 31 12:31:43 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 12:31:43 primo volumio[3097]: info: Executing endpoint metavolumio Oct 31 12:31:43 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 12:31:43 primo volumio[3097]: info: getStreamUrl took 599 milliseconds Oct 31 12:31:43 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=24044960&fmt=7&profile=raw&app_id=539451548&cid=2368250&etsp=1730377903&hmac=322uegQxM_RvMbt8VJ4azG7IN4s Oct 31 12:31:43 primo volumio[3097]: info: Executing endpoint metavolumio Oct 31 12:31:43 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 12:31:43 primo volumio[3097]: info: Executing endpoint metavolumio Oct 31 12:31:43 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 12:31:43 primo volumio[3097]: info: Executing endpoint metavolumio Oct 31 12:31:43 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 12:31:43 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 286962713 Oct 31 12:31:43 primo volumio[3097]: STREAMING PROXY: Client dropped request, destroying Oct 31 12:31:43 primo volumio[3097]: STREAMING PROXY: Handling url /?data=qobuz://song/13176083 Oct 31 12:31:43 primo volumio[3097]: Upnp client error: Error: This socket has been ended by the other party Oct 31 12:31:43 primo volumio[3097]: info: Oct 31 12:31:43 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:43 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:43 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/24044960" Oct 31 12:31:43 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/24044960" Oct 31 12:31:43 primo volumio[3097]: info: sendMpdCommand play took 2184 milliseconds Oct 31 12:31:43 primo volumio[3097]: info: ------------------------------ 2184ms Oct 31 12:31:43 primo volumio[3097]: info: sendMpdCommand status took 2182 milliseconds Oct 31 12:31:43 primo volumio[3097]: info: ------------------------------ 2182ms Oct 31 12:31:43 primo volumio[3097]: info: sendMpdCommand status took 2182 milliseconds Oct 31 12:31:43 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/24044960" took 1576 milliseconds Oct 31 12:31:43 primo volumio[3097]: verbose: ControllerMpd::parseState Oct 31 12:31:43 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 31 12:31:43 primo volumio[3097]: verbose: ControllerMpd::parseState Oct 31 12:31:43 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 31 12:31:43 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:43 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:43 primo volumio[3097]: info: Oct 31 12:31:43 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:43 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:43 primo volumio[3097]: info: Oct 31 12:31:43 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:43 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:43 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/24044960" took 15 milliseconds Oct 31 12:31:43 primo volumio[3097]: info: sendMpdCommand add "http://127.0.0.1:3245?data=qobuz://song/24044960" took 14 milliseconds Oct 31 12:31:43 primo volumio[3097]: info: ------------------------------ 19ms Oct 31 12:31:43 primo volumio[3097]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 31 12:31:43 primo volumio[3097]: info: sendMpdCommand playlistinfo took 6 milliseconds Oct 31 12:31:43 primo volumio[3097]: info: sendMpdCommand play took 6 milliseconds Oct 31 12:31:43 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:43 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:43 primo volumio[3097]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 31 12:31:43 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand play Oct 31 12:31:43 primo volumio[3097]: verbose: ControllerMpd::parseTrackInfo Oct 31 12:31:43 primo volumio[3097]: verbose: ControllerMpd::parseTrackInfo Oct 31 12:31:43 primo volumio[3097]: info: ControllerMpd::pushState Oct 31 12:31:43 primo volumio[3097]: info: CoreCommandRouter::servicePushState Oct 31 12:31:43 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:43 primo volumio[3097]: 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":"13176083","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/13176083","trackType":"qobuz"} Oct 31 12:31:43 primo volumio[3097]: verbose: CURRENT POSITION 12 Oct 31 12:31:43 primo volumio[3097]: info: CoreStateMachine::syncState stateService play Oct 31 12:31:43 primo volumio[3097]: info: CoreStateMachine::syncState currentStatus stop Oct 31 12:31:43 primo volumio[3097]: info: ControllerMpd::pushState Oct 31 12:31:43 primo volumio[3097]: info: CoreCommandRouter::servicePushState Oct 31 12:31:43 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:43 primo volumio[3097]: 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":"13176083","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/13176083","trackType":"qobuz"} Oct 31 12:31:43 primo volumio[3097]: verbose: CURRENT POSITION 12 Oct 31 12:31:43 primo volumio[3097]: info: CoreStateMachine::syncState stateService play Oct 31 12:31:43 primo volumio[3097]: info: CoreStateMachine::syncState currentStatus play Oct 31 12:31:43 primo volumio[3097]: info: Received an update from plugin. extracting info from payload Oct 31 12:31:43 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:43 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 12:31:43 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:43 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:43 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:43 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:43 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:43 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:43 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:43 primo volumio[3097]: info: ------------------------------ 2220ms Oct 31 12:31:43 primo volumio[3097]: info: ------------------------------ 2231ms Oct 31 12:31:43 primo volumio[3097]: info: Oct 31 12:31:43 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:43 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:43 primo volumio[3097]: info: Oct 31 12:31:43 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:43 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:43 primo volumio[3097]: info: ------------------------------ 51ms Oct 31 12:31:43 primo volumio[3097]: info: ------------------------------ 51ms Oct 31 12:31:43 primo volumio[3097]: info: sendMpdCommand play took 47 milliseconds Oct 31 12:31:43 primo volumio[3097]: info: sendMpdCommand play took 46 milliseconds Oct 31 12:31:43 primo volumio[3097]: info: ------------------------------ 11ms Oct 31 12:31:43 primo volumio[3097]: info: ------------------------------ 9ms Oct 31 12:31:43 primo volumio[3097]: info: Oct 31 12:31:43 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:43 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:43 primo volumio[3097]: info: Oct 31 12:31:43 primo volumio[3097]: ---------------------------- MPD announces system playlist update Oct 31 12:31:43 primo volumio[3097]: info: Ignoring MPD Status Update Oct 31 12:31:43 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:43 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:43 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:43 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:43 primo volumio[3097]: info: Executing endpoint getStreamUrlqobuz Oct 31 12:31:43 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , getStreamUrlAPI Oct 31 12:31:43 primo volumio[3097]: info: ------------------------------ 40ms Oct 31 12:31:43 primo volumio[3097]: info: ------------------------------ 39ms Oct 31 12:31:44 primo volumio[3097]: info: getStreamUrl took 606 milliseconds Oct 31 12:31:44 primo volumio[3097]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=3289791&eid=13176083&fmt=27&profile=raw&app_id=539451548&cid=2368250&etsp=1730377904&hmac=T-gMbcpKeNmHlP7EEfqRCdQ1afY Oct 31 12:31:44 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 328084816 Oct 31 12:31:44 primo volumio[3097]: info: Oct 31 12:31:44 primo volumio[3097]: ---------------------------- MPD announces state update: player Oct 31 12:31:44 primo volumio[3097]: info: ControllerMpd::getState Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand status Oct 31 12:31:44 primo kernel: aml_tdm_open Oct 31 12:31:44 primo kernel: Not init audio effects Oct 31 12:31:44 primo kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 Oct 31 12:31:44 primo volumio[3097]: info: Oct 31 12:31:44 primo volumio[3097]: ---------------------------- MPD announces state update: player Oct 31 12:31:44 primo volumio[3097]: info: ControllerMpd::getState Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand status Oct 31 12:31:44 primo volumio[3097]: info: Oct 31 12:31:44 primo volumio[3097]: ---------------------------- MPD announces state update: player Oct 31 12:31:44 primo volumio[3097]: info: ControllerMpd::getState Oct 31 12:31:44 primo kernel: set mclk:49152000, mpll:98304000, get mclk:49151901, mpll:98303801 Oct 31 12:31:44 primo kernel: asoc aml_dai_set_tdm_fmt, 0x4001, ffffffc03d2e3a18, id(1), clksel(1) Oct 31 12:31:44 primo kernel: aml_dai_set_tdm_fmt(), fmt not change Oct 31 12:31:44 primo kernel: dump_pcm_setting(ffffffc03d2e3a18) Oct 31 12:31:44 primo kernel: pcm_mode(1) Oct 31 12:31:44 primo kernel: sysclk(49152000) Oct 31 12:31:44 primo kernel: sysclk_bclk_ratio(4) Oct 31 12:31:44 primo kernel: bclk(12288000) Oct 31 12:31:44 primo kernel: bclk_lrclk_ratio(64) Oct 31 12:31:44 primo kernel: lrclk(192000) Oct 31 12:31:44 primo kernel: tx_mask(0x3) Oct 31 12:31:44 primo kernel: rx_mask(0x3) Oct 31 12:31:44 primo kernel: slots(2) Oct 31 12:31:44 primo kernel: slot_width(32) Oct 31 12:31:44 primo kernel: lane_mask_in(0x2) Oct 31 12:31:44 primo kernel: lane_mask_out(0x1) Oct 31 12:31:44 primo kernel: lane_oe_mask_in(0x0) Oct 31 12:31:44 primo kernel: lane_oe_mask_out(0x0) Oct 31 12:31:44 primo kernel: lane_lb_mask_in(0x0) Oct 31 12:31:44 primo kernel: aml_dai_set_tdm_sysclk(), mpll no change, keep clk Oct 31 12:31:44 primo kernel: aml_dai_set_tdm_sysclk(), mclk no change, keep clk Oct 31 12:31:44 primo kernel: set mclk:49152000, mpll:98304000, get mclk:49151901, mpll:98303801 Oct 31 12:31:44 primo kernel: aml_dai_set_clkdiv, div 4, clksel(1) Oct 31 12:31:44 primo kernel: aml_dai_set_bclk_ratio, select I2S mode Oct 31 12:31:44 primo kernel: aml_dai_tdm_hw_params(), enable mclk for TDM-B Oct 31 12:31:44 primo kernel: aml_tdm_prepare(), reset fddr Oct 31 12:31:44 primo kernel: spdif_a fifo ctrl, frddr:0 type:4, 24 bits, chmask 0x3, swap 0x10 Oct 31 12:31:44 primo kernel: spdif_info: rate: 192000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0xe00, ch1_r:0xe00 Oct 31 12:31:44 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Oct 31 12:31:44 primo kernel: tdm playback mute: 0, lane_cnt = 8 Oct 31 12:31:44 primo kernel: aml_tdm_prepare(), reset fddr Oct 31 12:31:44 primo kernel: spdif_a fifo ctrl, frddr:0 type:4, 24 bits, chmask 0x3, swap 0x10 Oct 31 12:31:44 primo kernel: spdif_info: rate: 192000, channel status ch0_l:0x100, ch0_r:0x100, ch1_l:0xe00, ch1_r:0xe00 Oct 31 12:31:44 primo kernel: audio_ddr_mngr: frddr_set_sharebuffer_enable sel:1, dst_src:3 Oct 31 12:31:44 primo kernel: tdm playback mute: 0, lane_cnt = 8 Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand status Oct 31 12:31:44 primo volumio[3097]: info: Oct 31 12:31:44 primo volumio[3097]: ---------------------------- MPD announces state update: player Oct 31 12:31:44 primo volumio[3097]: info: sendMpdCommand status took 9 milliseconds Oct 31 12:31:44 primo volumio[3097]: info: ControllerMpd::getState Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand status Oct 31 12:31:44 primo volumio[3097]: info: sendMpdCommand status took 9 milliseconds Oct 31 12:31:44 primo volumio[3097]: info: sendMpdCommand status took 4 milliseconds Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::parseState Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::parseState Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::parseState Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 31 12:31:44 primo volumio[3097]: info: Oct 31 12:31:44 primo volumio[3097]: ---------------------------- MPD announces state update: player Oct 31 12:31:44 primo volumio[3097]: info: ControllerMpd::getState Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand status Oct 31 12:31:44 primo volumio[3097]: info: Oct 31 12:31:44 primo volumio[3097]: ---------------------------- MPD announces state update: player Oct 31 12:31:44 primo volumio[3097]: info: ControllerMpd::getState Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand status Oct 31 12:31:44 primo volumio[3097]: info: sendMpdCommand status took 11 milliseconds Oct 31 12:31:44 primo volumio[3097]: info: sendMpdCommand playlistinfo took 9 milliseconds Oct 31 12:31:44 primo volumio[3097]: info: sendMpdCommand playlistinfo took 9 milliseconds Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::parseState Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::parseTrackInfo Oct 31 12:31:44 primo volumio[3097]: info: ControllerMpd::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::servicePushState Oct 31 12:31:44 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:44 primo volumio[3097]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":548,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"13176083","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/13176083","trackType":"qobuz"} Oct 31 12:31:44 primo volumio[3097]: verbose: CURRENT POSITION 12 Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::syncState stateService play Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::syncState currentStatus play Oct 31 12:31:44 primo volumio[3097]: info: Received an update from plugin. extracting info from payload Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:44 primo volumio[3097]: info: ControllerMpd::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::servicePushState Oct 31 12:31:44 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:44 primo volumio[3097]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":548,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"13176083","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/13176083","trackType":"qobuz"} Oct 31 12:31:44 primo volumio[3097]: verbose: CURRENT POSITION 12 Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::syncState stateService play Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::syncState currentStatus play Oct 31 12:31:44 primo volumio[3097]: info: Received an update from plugin. extracting info from payload Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:44 primo volumio[3097]: info: ControllerMpd::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::servicePushState Oct 31 12:31:44 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:44 primo volumio[3097]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":548,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"13176083","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/13176083","trackType":"qobuz"} Oct 31 12:31:44 primo volumio[3097]: verbose: CURRENT POSITION 12 Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::syncState stateService play Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::syncState currentStatus play Oct 31 12:31:44 primo volumio[3097]: info: Received an update from plugin. extracting info from payload Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:44 primo volumio[3097]: info: ------------------------------ 103ms Oct 31 12:31:44 primo volumio[3097]: info: ------------------------------ 104ms Oct 31 12:31:44 primo volumio[3097]: info: ------------------------------ 105ms Oct 31 12:31:44 primo volumio[3097]: info: sendMpdCommand status took 93 milliseconds Oct 31 12:31:44 primo volumio[3097]: info: sendMpdCommand status took 92 milliseconds Oct 31 12:31:44 primo volumio[3097]: info: sendMpdCommand playlistinfo took 89 milliseconds Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::parseState Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::parseState Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::parseTrackInfo Oct 31 12:31:44 primo volumio[3097]: info: ControllerMpd::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::servicePushState Oct 31 12:31:44 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:44 primo volumio[3097]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":548,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"13176083","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/13176083","trackType":"qobuz"} Oct 31 12:31:44 primo volumio[3097]: verbose: CURRENT POSITION 12 Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::syncState stateService play Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::syncState currentStatus play Oct 31 12:31:44 primo volumio[3097]: info: Received an update from plugin. extracting info from payload Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:44 primo kernel: asoc-aml-card auge_sound: tdm playback enable Oct 31 12:31:44 primo kernel: spdif_a is set to enable Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:44 primo volumio[3097]: info: ------------------------------ 132ms Oct 31 12:31:44 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:44 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:44 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:44 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:44 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:44 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:44 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:44 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:44 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:44 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:44 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:44 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:44 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:44 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:44 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:44 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:44 primo volumio[3097]: info: sendMpdCommand playlistinfo took 87 milliseconds Oct 31 12:31:44 primo volumio[3097]: verbose: ControllerMpd::parseTrackInfo Oct 31 12:31:44 primo volumio[3097]: info: ControllerMpd::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::servicePushState Oct 31 12:31:44 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:44 primo volumio[3097]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":548,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"13176083","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/13176083","trackType":"qobuz"} Oct 31 12:31:44 primo volumio[3097]: verbose: CURRENT POSITION 12 Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::syncState stateService play Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::syncState currentStatus play Oct 31 12:31:44 primo volumio[3097]: info: Received an update from plugin. extracting info from payload Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:44 primo volumio[3097]: info: ControllerMpd::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::servicePushState Oct 31 12:31:44 primo volumio[3097]: info: CorePlayQueue::getTrack 12 Oct 31 12:31:44 primo volumio[3097]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":548,"samplerate":"192 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"13176083","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/13176083","trackType":"qobuz"} Oct 31 12:31:44 primo volumio[3097]: verbose: CURRENT POSITION 12 Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::syncState stateService play Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::syncState currentStatus play Oct 31 12:31:44 primo volumio[3097]: info: Received an update from plugin. extracting info from payload Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:44 primo volumio[3097]: info: CoreStateMachine::pushState Oct 31 12:31:44 primo volumio[3097]: info: CoreCommandRouter::volumioPushState Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output update for this device Oct 31 12:31:44 primo volumio[3097]: info: MRS: Pushing multiroomSync output Oct 31 12:31:45 primo volumio[3097]: info: ------------------------------ 233ms Oct 31 12:31:45 primo volumio[3097]: info: ------------------------------ 232ms Oct 31 12:31:45 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:45 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:45 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:45 primo volumio[3097]: info: Updating RAAT Signal Path Oct 31 12:31:45 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:45 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:45 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:45 primo volumio[3097]: info: Signalling Playback active due to playback status change Oct 31 12:31:45 primo volumio[3097]: info: Executing endpoint metavolumio Oct 31 12:31:45 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 12:31:45 primo volumio[3097]: info: Executing endpoint metavolumio Oct 31 12:31:45 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 12:31:45 primo volumio[3097]: info: Executing endpoint metavolumio Oct 31 12:31:45 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 12:31:45 primo volumio[3097]: info: Executing endpoint metavolumio Oct 31 12:31:45 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 12:31:45 primo volumio[3097]: info: Executing endpoint metavolumio Oct 31 12:31:45 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 12:31:45 primo volumio[3097]: info: Executing endpoint metavolumio Oct 31 12:31:45 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 31 12:31:59 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 31 12:31:59 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 31 12:31:59 primo volumio[3097]: info: Discovery: Getting this device information Oct 31 12:31:59 primo volumio[3097]: info: CoreCommandRouter::volumioGetState Oct 31 12:31:59 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 31 12:32:05 primo volumio[3097]: info: CoreCommandRouter::volumioGetQueue Oct 31 12:32:05 primo volumio[3097]: info: CoreStateMachine::getQueue Oct 31 12:32:05 primo volumio[3097]: info: CorePlayQueue::getQueue Oct 31 12:32:06 primo volumio[3097]: STREAMING PROXY: Response: 200, length: 107088375 Oct 31 12:32:27 primo volumio[3097]: Searching all installed plugins Oct 31 12:32:27 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 12:32:27 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: , search Oct 31 12:32:27 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 31 12:32:27 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 31 12:32:27 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 31 12:32:27 primo volumio[3097]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 31 12:32:27 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 31 12:32:27 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 31 12:32:27 primo volumio[3097]: Searching all installed plugins Oct 31 12:32:27 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 12:32:27 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: , search Oct 31 12:32:27 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 31 12:32:27 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 31 12:32:27 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 31 12:32:27 primo volumio[3097]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 31 12:32:27 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 31 12:32:27 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 31 12:32:28 primo volumio[3097]: Searching all installed plugins Oct 31 12:32:28 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 12:32:28 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: , search Oct 31 12:32:28 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 31 12:32:28 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 31 12:32:28 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 31 12:32:28 primo volumio[3097]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 31 12:32:28 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 31 12:32:28 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 31 12:32:29 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 31 12:32:29 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 31 12:32:29 primo volumio[3097]: info: Discovery: Getting this device information Oct 31 12:32:29 primo volumio[3097]: info: CoreCommandRouter::volumioGetState Oct 31 12:32:29 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 31 12:32:29 primo volumio[3097]: info: searchQOBUZUri took 2739 milliseconds Oct 31 12:32:29 primo volumio[3097]: info: All search sources collected, pushing search results Oct 31 12:32:29 primo volumio[3097]: Searching all installed plugins Oct 31 12:32:29 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 12:32:29 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: , search Oct 31 12:32:29 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 31 12:32:30 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 31 12:32:30 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 31 12:32:30 primo volumio[3097]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 31 12:32:30 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 31 12:32:30 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 31 12:32:30 primo volumio[3097]: info: searchQOBUZUri took 2475 milliseconds Oct 31 12:32:30 primo volumio[3097]: info: All search sources collected, pushing search results Oct 31 12:32:30 primo volumio[3097]: Searching all installed plugins Oct 31 12:32:30 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 12:32:30 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: , search Oct 31 12:32:30 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 31 12:32:30 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 31 12:32:30 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 31 12:32:30 primo volumio[3097]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 31 12:32:30 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 31 12:32:30 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 31 12:32:31 primo volumio[3097]: info: searchQOBUZUri took 2282 milliseconds Oct 31 12:32:31 primo volumio[3097]: info: All search sources collected, pushing search results Oct 31 12:32:31 primo volumio[3097]: Searching all installed plugins Oct 31 12:32:31 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 12:32:31 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: , search Oct 31 12:32:31 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 31 12:32:31 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 31 12:32:31 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 31 12:32:31 primo volumio[3097]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 31 12:32:31 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 31 12:32:31 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 31 12:32:32 primo volumio[3097]: info: searchQOBUZUri took 2643 milliseconds Oct 31 12:32:32 primo volumio[3097]: info: All search sources collected, pushing search results Oct 31 12:32:32 primo volumio[3097]: info: searchQOBUZUri took 2210 milliseconds Oct 31 12:32:32 primo volumio[3097]: info: All search sources collected, pushing search results Oct 31 12:32:33 primo volumio[3097]: Searching all installed plugins Oct 31 12:32:33 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 31 12:32:33 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: , search Oct 31 12:32:33 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: mpd , search Oct 31 12:32:33 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , search Oct 31 12:32:33 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Oct 31 12:32:33 primo volumio[3097]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Oct 31 12:32:33 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: webradio , search Oct 31 12:32:33 primo volumio[3097]: info: CoreCommandRouter::executeOnPlugin: qobuz , search Oct 31 12:32:33 primo volumio[3097]: info: searchQOBUZUri took 2135 milliseconds Oct 31 12:32:33 primo volumio[3097]: info: All search sources collected, pushing search results Oct 31 12:32:35 primo volumio[3097]: info: searchQOBUZUri took 2336 milliseconds Oct 31 12:32:35 primo volumio[3097]: info: All search sources collected, pushing search results Oct 31 12:32:44 primo volumio[3097]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 31 12:32:44 primo volumio[3097]: Error: read ETIMEDOUT Oct 31 12:32:44 primo volumio[3097]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:209:20) { Oct 31 12:32:44 primo volumio[3097]: errno: -110, Oct 31 12:32:44 primo volumio[3097]: code: 'ETIMEDOUT', Oct 31 12:32:44 primo volumio[3097]: syscall: 'read' Oct 31 12:32:44 primo volumio[3097]: } Oct 31 12:32:44 primo volumio[3097]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 31 12:32:44 primo sudo[6400]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-31 12:31 Oct 31 12:32:44 primo sudo[6400]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 06:34:13 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="4afef88585183bd857d5aee3dd000abc"