Feb 17 22:02:07 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Feb 17 22:02:07 volumio-okto volumio[1992]: info: Received Get System Info
Feb 17 22:02:07 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Feb 17 22:02:07 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Feb 17 22:02:07 volumio-okto volumio[1992]: info: Discovery: Getting this device information
Feb 17 22:02:07 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:02:07 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Feb 17 22:02:08 volumio-okto sudo[2285]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 17 22:02:08 volumio-okto sudo[2285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 22:02:08 volumio-okto sudo[2285]: pam_unix(sudo:session): session closed for user root
Feb 17 22:02:08 volumio-okto sudo[2287]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 17 22:02:08 volumio-okto sudo[2287]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 22:02:08 volumio-okto sudo[2287]: pam_unix(sudo:session): session closed for user root
Feb 17 22:02:08 volumio-okto volumio[1992]: verbose: New Socket.io Connection to 192.168.0.149 from 192.168.0.54 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/144.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:02:08 volumio-okto volumio[1992]: info: Received Get System Info
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Feb 17 22:02:08 volumio-okto volumio[1992]: info: Discovery: Getting this device information
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetVisibleSources
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Feb 17 22:02:08 volumio-okto volumio[1992]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom
Feb 17 22:02:08 volumio-okto volumio[1992]: info: Received Get System Info
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Feb 17 22:02:08 volumio-okto volumio[1992]: info: Discovery: Getting this device information
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:02:08 volumio-okto volumio[1992]: info: Listing playlists
Feb 17 22:02:08 volumio-okto volumio[1992]: info: Received Get System Info
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Feb 17 22:02:08 volumio-okto volumio[1992]: info: Discovery: Getting this device information
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:02:08 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Feb 17 22:02:09 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:02:10 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetQueue
Feb 17 22:02:10 volumio-okto volumio[1992]: info: CoreStateMachine::getQueue
Feb 17 22:02:10 volumio-okto volumio[1992]: info: CorePlayQueue::getQueue
Feb 17 22:02:11 volumio-okto volumio[1992]: info: Executing endpoint metavolumio
Feb 17 22:02:11 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Feb 17 22:02:11 volumio-okto volumio[1992]: info: Executing endpoint metavolumio
Feb 17 22:02:11 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Feb 17 22:02:11 volumio-okto volumio[1992]: info: Executing endpoint metavolumio
Feb 17 22:02:11 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Feb 17 22:02:12 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:02:14 volumio-okto volumio[1992]: info: Executing endpoint metavolumio
Feb 17 22:02:14 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Feb 17 22:02:14 volumio-okto volumio[1992]: info: Executing endpoint metavolumio
Feb 17 22:02:14 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Feb 17 22:02:14 volumio-okto volumio[1992]: info: Executing endpoint metavolumio
Feb 17 22:02:14 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Feb 17 22:02:18 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Feb 17 22:02:20 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Feb 17 22:02:20 volumio-okto volumio[1992]: info: CURURI: music-library
Feb 17 22:02:20 volumio-okto volumio[1992]: error: Failed LSINFO: null
Feb 17 22:02:20 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:32 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:32 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:34 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:34 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:34 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:36 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:36 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:37 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:37 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:38 volumio-okto volumio[1992]: error: error
Feb 17 22:02:38 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:38 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:40 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:41 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:41 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:41 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:43 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:45 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:49 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:51 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:52 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:52 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:53 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:53 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:53 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:53 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:53 volumio-okto volumio[1992]: error: socket hang up {"code":"ECONNRESET"}
Feb 17 22:02:53 volumio-okto volumio[1992]: error: Failed to execute browseSource:
Feb 17 22:02:54 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:54 volumio-okto volumio[1992]: error: socket hang up {"code":"ECONNRESET"}
Feb 17 22:02:54 volumio-okto volumio[1992]: error: Failed to execute browseSource:
Feb 17 22:02:55 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:55 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:02:56 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:56 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:57 volumio-okto volumio[1992]: error: socket hang up {"code":"ECONNRESET"}
Feb 17 22:02:57 volumio-okto volumio[1992]: error: Failed to execute browseSource:
Feb 17 22:02:57 volumio-okto volumio[1992]: error: socket hang up {"code":"ECONNRESET"}
Feb 17 22:02:57 volumio-okto volumio[1992]: error: Failed to execute browseSource:
Feb 17 22:02:57 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:57 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:57 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:57 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:57 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82093
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82071
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82072
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82073
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82074
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82075
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82076
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82077
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82078
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82079
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82080
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82081
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82082
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82094
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82083
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82084
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82085
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82086
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82087
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82088
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82089
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82090
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82091
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82092
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@34308
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@34309
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@34310
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@34311
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149069
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149077
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149058
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149059
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149060
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149061
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149062
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149063
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149064
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149065
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149066
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149067
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149068
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149078
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149070
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149071
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149072
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149073
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149074
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149075
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@149076
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@188992
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@188993
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@188994
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@188995
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@188996
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@188997
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@188998
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@188999
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@189000
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@204610
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@32591
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@32592
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@32593
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@32594
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@32595
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@32596
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@32597
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@156990
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@156991
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@156992
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@156993
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@156994
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@156995
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@156996
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@156997
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@174243
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@174244
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@174245
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@174246
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@174247
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@174248
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@174249
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@174250
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159486
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159487
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159488
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159489
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159490
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159491
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159492
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159493
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159494
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159495
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159496
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159497
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159498
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159499
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159500
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159501
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159502
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preloading song: upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@159503
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Exploding uri upnp/http://192.168.0.4:50001/ContentDirectory/control@23$@82093 in service upnp_browser
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:58 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:59 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:59 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:59 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:59 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:59 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:02:59 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:03:03 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri
Feb 17 22:03:03 volumio-okto volumio[1992]: info: Preload queue cleared
Feb 17 22:03:18 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:03:19 volumio-okto volumio[1992]: info: Pushing metadata
Feb 17 22:03:19 volumio-okto volumio[1992]: info: CoreCommandRouter::servicePushState
Feb 17 22:03:19 volumio-okto volumio[1992]: info: CoreStateMachine::pushState
Feb 17 22:03:19 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 17 22:03:19 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioPushState
Feb 17 22:03:19 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:03:19 volumio-okto volumio[1992]: info: CoreCommandRouter::servicePushState
Feb 17 22:03:19 volumio-okto volumio[1992]: info: CoreStateMachine::pushState
Feb 17 22:03:19 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioPushState
Feb 17 22:03:19 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:03:19 volumio-okto volumio[1992]: info: CoreCommandRouter::servicePushState
Feb 17 22:03:19 volumio-okto volumio[1992]: info: CoreStateMachine::pushState
Feb 17 22:03:19 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 17 22:03:19 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioPushState
Feb 17 22:03:19 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:03:19 volumio-okto volumio[1992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 17 22:03:19 volumio-okto volumio[1992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 17 22:03:19 volumio-okto volumio[1992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 17 22:03:22 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:03:24 volumio-okto volumio[1992]: info: Executing endpoint metavolumio
Feb 17 22:03:24 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Feb 17 22:03:24 volumio-okto volumio[1992]: info: Executing endpoint metavolumio
Feb 17 22:03:24 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Feb 17 22:03:24 volumio-okto volumio[1992]: info: Executing endpoint metavolumio
Feb 17 22:03:24 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioNext
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreStateMachine::next
Feb 17 22:03:25 volumio-okto volumio[1992]: info: Received next
Feb 17 22:03:25 volumio-okto vtcs[2540]: [close:85] Entering
Feb 17 22:03:25 volumio-okto vtcs[2540]: [feedThread:276] Exiting
Feb 17 22:03:25 volumio-okto vtcs[2540]: [close:100] Exiting
Feb 17 22:03:25 volumio-okto volumio[1992]: info: Pushing metadata
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::servicePushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreStateMachine::pushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioPushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::servicePushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreStateMachine::pushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioPushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::servicePushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreStateMachine::pushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioPushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:03:25 volumio-okto volumio[1992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 17 22:03:25 volumio-okto volumio[1992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 17 22:03:25 volumio-okto volumio[1992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 17 22:03:25 volumio-okto vtcs[2540]: [close:85] Entering
Feb 17 22:03:25 volumio-okto vtcs[2540]: [close:100] Exiting
Feb 17 22:03:25 volumio-okto volumio[1992]: info: Pushing metadata
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::servicePushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreStateMachine::pushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioPushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::servicePushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreStateMachine::pushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioPushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:03:25 volumio-okto volumio[1992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 17 22:03:25 volumio-okto volumio[1992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 17 22:03:25 volumio-okto vtcs[2540]: [close:85] Entering
Feb 17 22:03:25 volumio-okto vtcs[2540]: [close:100] Exiting
Feb 17 22:03:25 volumio-okto vtcs[2540]: [open:50] Opening with sample rate: 44100, type: 0
Feb 17 22:03:25 volumio-okto vtcs[2540]: [start:106] Entering
Feb 17 22:03:25 volumio-okto vtcs[2540]: [start:113] Reopening PCM device...
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::servicePushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreStateMachine::pushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioPushState
Feb 17 22:03:25 volumio-okto vtcs[2540]: [start:115] PCM opened successfully.
Feb 17 22:03:25 volumio-okto vtcs[2540]: [start:120] Exiting
Feb 17 22:03:25 volumio-okto vtcs[2540]: [feedThread:223] Entering
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:03:25 volumio-okto volumio[1992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::servicePushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreStateMachine::pushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioPushState
Feb 17 22:03:25 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:03:25 volumio-okto volumio[1992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 17 22:03:26 volumio-okto volumio[1992]: info: CoreCommandRouter::servicePushState
Feb 17 22:03:26 volumio-okto volumio[1992]: info: CoreStateMachine::pushState
Feb 17 22:03:26 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 17 22:03:26 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioPushState
Feb 17 22:03:26 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:03:26 volumio-okto volumio[1992]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 17 22:03:27 volumio-okto volumio[1992]: info: Executing endpoint metavolumio
Feb 17 22:03:27 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Feb 17 22:03:27 volumio-okto volumio[1992]: info: Executing endpoint metavolumio
Feb 17 22:03:27 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Feb 17 22:03:27 volumio-okto volumio[1992]: info: Executing endpoint metavolumio
Feb 17 22:03:27 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Feb 17 22:03:34 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetState
Feb 17 22:03:34 volumio-okto systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Feb 17 22:03:34 volumio-okto systemd[1]: setdatetime-helper.service: Deactivated successfully.
Feb 17 22:03:34 volumio-okto systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service.
Feb 17 22:03:36 volumio-okto volumio[1992]: info: Executing endpoint metavolumio
Feb 17 22:03:36 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Feb 17 22:03:36 volumio-okto volumio[1992]: info: Executing endpoint metavolumio
Feb 17 22:03:36 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Feb 17 22:03:36 volumio-okto volumio[1992]: info: Executing endpoint metavolumio
Feb 17 22:03:36 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::getUIConfigOnPlugin
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::getUIConfigOnPlugin
Feb 17 22:03:41 volumio-okto volumio[1992]: info: Retrieving Cloud Streaming UI
Feb 17 22:03:41 volumio-okto volumio[1992]: info: Getting Tidal Cloud Configuration
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::getUIConfigOnPlugin
Feb 17 22:03:41 volumio-okto volumio[1992]: info: Getting Qobuz Cloud Configuration
Feb 17 22:03:41 volumio-okto volumio[1992]: info: Asking plugin for UI Config
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::getUIConfigOnPlugin
Feb 17 22:03:41 volumio-okto volumio[1992]: info: Getting Spotify Cloud Configuration
Feb 17 22:03:41 volumio-okto volumio[1992]: info: Asking plugin for UI Config
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::getUIConfigOnPlugin
Feb 17 22:03:41 volumio-okto volumio[1992]: info: Saving Spotify Acccount
Feb 17 22:03:41 volumio-okto volumio[1992]: info: Got it
Feb 17 22:03:41 volumio-okto volumio[1992]: error: Could not retrieve Spotify Config from plugin Spotify: no section found
Feb 17 22:03:41 volumio-okto volumio[1992]: info: Got Tidal Cloud Configuration
Feb 17 22:03:41 volumio-okto volumio[1992]: info: Got it
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::getUIConfigOnPlugin
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetBrowseSources
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetBrowseSources
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioGetBrowseSources
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Feb 17 22:03:41 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares
Feb 17 22:03:45 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Feb 17 22:03:49 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Feb 17 22:03:53 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Feb 17 22:03:57 volumio-okto volumio[1992]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Feb 17 22:03:58 volumio-okto volumio[1992]: info: Enabling MyMusic plugin bluetooth
Feb 17 22:03:58 volumio-okto volumio[1992]: info: [MyVolumio PluginManager] Enabling and starting plugin audio_interface bluetooth
Feb 17 22:03:58 volumio-okto volumio[1992]: info: Enabling plugin bluetooth
Feb 17 22:03:58 volumio-okto volumio[1992]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth
Feb 17 22:03:58 volumio-okto volumio[1992]: ------------------------------------ BT MESSAGE: [FUNC] onStart
Feb 17 22:03:58 volumio-okto volumio[1992]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service
Feb 17 22:03:58 volumio-okto volumio[1992]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp
Feb 17 22:03:58 volumio-okto volumio[1992]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/
Feb 17 22:03:58 volumio-okto volumio[1992]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready.
Feb 17 22:03:58 volumio-okto bluetoothd[769]: Path / reserved for Adv Monitor app :1.31
Feb 17 22:03:58 volumio-okto bluetoothd[769]: Adv Monitor app :1.31 disconnected from D-Bus
Feb 17 22:03:58 volumio-okto volumio[1992]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on
Feb 17 22:03:58 volumio-okto sudo[2654]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service
Feb 17 22:03:58 volumio-okto sudo[2654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 22:03:58 volumio-okto systemd[1]: Started volumiobt.service - Volumio Bluetooth Module.
Feb 17 22:03:58 volumio-okto sudo[2654]: pam_unix(sudo:session): session closed for user root
Feb 17 22:03:58 volumio-okto volumio[1992]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully
Feb 17 22:03:58 volumio-okto volumio[1992]: info: CoreCommandRouter::volumioStop
Feb 17 22:03:58 volumio-okto volumio[1992]: info: CoreStateMachine::stop
Feb 17 22:03:58 volumio-okto volumio[1992]: info: CoreStateMachine::serviceStop
Feb 17 22:03:58 volumio-okto volumio[1992]: info: CoreCommandRouter::serviceStop
Feb 17 22:03:58 volumio-okto volumio[1992]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 17 22:03:58 volumio-okto vtcs[2540]: [close:85] Entering
Feb 17 22:03:58 volumio-okto volumiobt[2657]: INFO [BTSTART] Ensuring Bluetooth directory exists...
Feb 17 22:03:58 volumio-okto volumio[1992]: TypeError: Cannot read properties of undefined (reading 'then')
Feb 17 22:03:58 volumio-okto volumio[1992]: at /myvolumio/plugins/audio_interface/bluetooth/bluetooth_real:1:12468
Feb 17 22:03:58 volumio-okto volumio[1992]: at ChildProcess.exithandler (node:child_process:413:7)
Feb 17 22:03:58 volumio-okto volumio[1992]: at ChildProcess.emit (node:events:514:28)
Feb 17 22:03:58 volumio-okto volumio[1992]: at maybeClose (node:internal/child_process:1105:16)
Feb 17 22:03:58 volumio-okto volumio[1992]: at ChildProcess._handle.onexit (node:internal/child_process:305:5)
Feb 17 22:03:58 volumio-okto volumio[1992]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 17 22:03:58 volumio-okto vtcs[2540]: [feedThread:276] Exiting
Feb 17 22:03:58 volumio-okto vtcs[2540]: [close:100] Exiting
Feb 17 22:03:58 volumio-okto sudo[2658]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth
Feb 17 22:03:58 volumio-okto sudo[2658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 22:03:58 volumio-okto sudo[2658]: pam_unix(sudo:session): session closed for user root
Feb 17 22:03:58 volumio-okto sudo[2664]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth
Feb 17 22:03:58 volumio-okto sudo[2664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 17 22:03:58 volumio-okto vtcs[2540]: [2026-02-17 22:03:58] [info] asio async_shutdown error: asio.misc:2 (End of file)
Feb 17 22:03:58 volumio-okto sudo[2664]: pam_unix(sudo:session): session closed for user root
Feb 17 22:03:58 volumio-okto volumiobt[2674]: INFO [BTSTART] Powering on Bluetooth if needed...
Feb 17 22:03:59 volumio-okto bluetoothd[769]: Adv Monitor app :1.32 disconnected from D-Bus
Feb 17 22:03:59 volumio-okto volumiobt[2677]: INFO [BTSTART] Making Bluetooth discoverable and pairable...
Feb 17 22:03:59 volumio-okto volumiobt[2679]: [176B blob data]
Feb 17 22:03:59 volumio-okto volumiobt[2679]: [157B blob data]
Feb 17 22:03:59 volumio-okto volumiobt[2679]: [157B blob data]
Feb 17 22:03:59 volumio-okto volumiobt[2679]: [157B blob data]
Feb 17 22:03:59 volumio-okto volumiobt[2679]: [113B blob data]
Feb 17 22:03:59 volumio-okto volumiobt[2679]: [bluetoothctl]> discoverable on
Feb 17 22:03:59 volumio-okto volumiobt[2679]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended
Feb 17 22:03:59 volumio-okto volumiobt[2679]: [bluetoothctl]> pairable on
Feb 17 22:03:59 volumio-okto bluetoothd[769]: Path / reserved for Adv Monitor app :1.33
Feb 17 22:03:59 volumio-okto bluetoothd[769]: Adv Monitor app :1.33 disconnected from D-Bus
Feb 17 22:03:59 volumio-okto volumiobt[2679]: [bluetoothctl]>
Feb 17 22:03:59 volumio-okto volumiobt[2680]: INFO [BTSTART] Registering Bluetooth agent...
Feb 17 22:03:59 volumio-okto volumiobt[2681]: [NEW] Media /org/bluez/hci0
Feb 17 22:03:59 volumio-okto volumiobt[2681]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb
Feb 17 22:03:59 volumio-okto volumiobt[2681]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb
Feb 17 22:03:59 volumio-okto volumiobt[2681]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb
Feb 17 22:03:59 volumio-okto bluetoothd[769]: Adv Monitor app :1.34 disconnected from D-Bus
Feb 17 22:03:59 volumio-okto volumiobt[2682]: No agent is registered
Feb 17 22:03:59 volumio-okto volumiobt[2682]: [NEW] Media /org/bluez/hci0
Feb 17 22:03:59 volumio-okto volumiobt[2682]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb
Feb 17 22:03:59 volumio-okto volumiobt[2682]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb
Feb 17 22:03:59 volumio-okto volumiobt[2682]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb
Feb 17 22:03:59 volumio-okto bluetoothd[769]: Adv Monitor app :1.35 disconnected from D-Bus
Feb 17 22:03:59 volumio-okto volumiobt[2683]: INFO [BTSTART] Agent registered successfully.
Feb 17 22:03:59 volumio-okto volumiobt[2684]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)...
Feb 17 22:03:59 volumio-okto vtcs[2540]: [2026-02-17 22:03:59.306] [tisoc] [warning] [PlaybackControllerImpl.cpp:498] Illegal state:0
Feb 17 22:03:59 volumio-okto sudo[2688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-17 22:02'
Feb 17 22:03:59 volumio-okto sudo[2688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="a78d359cf1dc63ac74e9d151015afd30d31a709a"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026"
VOLUMIO_VERSION="4.096"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"