Mar 28 12:30:00 volumio systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel.
Mar 28 12:30:00 volumio sudo[2364]: pam_unix(sudo:session): session closed for user root
Mar 28 12:30:00 volumio autossh[2367]: port set to 0, monitoring disabled
Mar 28 12:30:00 volumio autossh[2367]: starting ssh (count 1)
Mar 28 12:30:00 volumio autossh[2367]: ssh child pid is 2370
Mar 28 12:30:00 volumio volumio[1390]: info: Preload queue cleared
Mar 28 12:30:00 volumio volumiossh-tunnel[2370]: Warning: Permanently added '[eu10.myvolumio.org]:2222' (RSA) to the list of known hosts.
Mar 28 12:30:00 volumio volumio[1390]: info: Remote SSH Started
Mar 28 12:30:01 volumio volumio5-onboarding[1781]: time=2026-03-28T12:30:01.069+01:00 level=ERROR msg="failed to broadcast user info" component=state error="failed to get logged user: could not get custom token: failed to fetch custom token: Get \"https://functions.volumio.cloud/api/v1/getCustomToken?idToken=eyJhbGciOiJSUzI1NiIsImtpZCI6IjM3MzAwNzY5YTA3ZTA1MTE2ZjdlNTEzOGZhOTA5MzY4NWVlYmMyNDAiLCJ0eXAiOiJKV1QifQ.eyJpc3MiOiJodHRwczovL3NlY3VyZXRva2VuLmdvb2dsZS5jb20vbXl2b2x1bWlvIiwiYXVkIjoibXl2b2x1bWlvIiwiYXV0aF90aW1lIjoxNzc0Njk3Mzk5LCJ1c2VyX2lkIjoiNXhrbFdvcWdBc2dGRGFuaEJFM1RlUml4OWJJMiIsInN1YiI6IjV4a2xXb3FnQXNnRkRhbmhCRTNUZVJpeDliSTIiLCJpYXQiOjE3NzQ2OTczOTksImV4cCI6MTc3NDcwMDk5OSwiZW1haWwiOiJzdGVmYW5vbG1vQGdtYWlsLmNvbSIsImVtYWlsX3ZlcmlmaWVkIjp0cnVlLCJmaXJlYmFzZSI6eyJpZGVudGl0aWVzIjp7ImVtYWlsIjpbInN0ZWZhbm9sbW9AZ21haWwuY29tIl19LCJzaWduX2luX3Byb3ZpZGVyIjoiY3VzdG9tIn19.YOWuZuLEJz26kYsmvkA6eqBr3JjervQyR0KKOqm09fnori4JW1K7uPd-x-M0oB_D6PEWhXvHKPOgFkkxcB3snvb4jvukdGjLEgLMGD94R_4WaClt4Q0FPTCsv54eZ2bl0T1AWedpvcgvfxMfNBkCJ59gG30m6H9a8H28wDVkSZHKIvjbXXYc12OAoNkig3Tu_XjS44yDLoYAz5OVIA979ne2AEK5rjc_UkkZGX0YbVMWrCUkJymYf3V6OaWtuWDWSMm12NKFLxQpRecQQV33II7cR6UxKExaUAIUjQLmcKHnRQMdE5Yoe7Nwgxf_xTOSFTm_M78ZQtq-jm2ybbUPBA\": context deadline exceeded"
Mar 28 12:30:01 volumio volumio[1390]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Mar 28 12:30:01 volumio volumio[1390]: info: Asound.conf file written
Mar 28 12:30:01 volumio sudo[2373]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
Mar 28 12:30:01 volumio sudo[2373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 28 12:30:01 volumio sudo[2373]: pam_unix(sudo:session): session closed for user root
Mar 28 12:30:01 volumio volumio[1390]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:0 use case configuration -2
Mar 28 12:30:01 volumio volumio[1390]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:1 use case configuration -2
Mar 28 12:30:01 volumio volumio[1390]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:2 use case configuration -2
Mar 28 12:30:01 volumio volumio[1390]: alsa-lib main.c:1541:(snd_use_case_mgr_open) error: failed to import hw:3 use case configuration -2
Mar 28 12:30:01 volumio volumio[1390]: info: Output device has changed, restarting MPD
Mar 28 12:30:01 volumio volumio[1390]: info: Output device has changed, restarting Shairport Sync
Mar 28 12:30:01 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 28 12:30:01 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 28 12:30:01 volumio sudo[2379]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Mar 28 12:30:01 volumio sudo[2379]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 28 12:30:01 volumio sudo[2381]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Mar 28 12:30:01 volumio sudo[2381]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 28 12:30:01 volumio sudo[2379]: pam_unix(sudo:session): session closed for user root
Mar 28 12:30:01 volumio volumio[1390]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Mar 28 12:30:01 volumio volumio[1390]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Mar 28 12:30:01 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 28 12:30:01 volumio volumio[1390]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth
Mar 28 12:30:01 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Mar 28 12:30:01 volumio volumio[1390]: ------------------------------------ BT MESSAGE: [FUNC] onStart
Mar 28 12:30:01 volumio volumio[1390]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service
Mar 28 12:30:01 volumio volumio[1390]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp
Mar 28 12:30:01 volumio volumio[1390]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/
Mar 28 12:30:01 volumio volumio[1390]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready.
Mar 28 12:30:01 volumio volumio[1390]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom
Mar 28 12:30:01 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus
Mar 28 12:30:01 volumio volumio[1390]: info: MRS: Pushing multiroomSync output for this device
Mar 28 12:30:02 volumio volumio[1390]: info: MRS: Pushing multiroomSync output
Mar 28 12:30:02 volumio volumio[1390]: info: Adding audio output:
Mar 28 12:30:02 volumio volumio[1390]: info: Adding audio output:
Mar 28 12:30:02 volumio bluetoothd[931]: Path / reserved for Adv Monitor app :1.29
Mar 28 12:30:02 volumio bluetoothd[931]: Adv Monitor app :1.29 disconnected from D-Bus
Mar 28 12:30:02 volumio volumio[1390]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Mar 28 12:30:02 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 28 12:30:02 volumio systemd[1]: mpd.service: Deactivated successfully.
Mar 28 12:30:02 volumio volumio[1390]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio
Mar 28 12:30:02 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Mar 28 12:30:02 volumio systemd[1]: mpd.service: Consumed 3.135s CPU time.
Mar 28 12:30:02 volumio systemd[1]: mpd.socket: Deactivated successfully.
Mar 28 12:30:02 volumio volumio[1390]: info: Adding METAVOLUMIO REST API Endpoints
Mar 28 12:30:02 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Mar 28 12:30:02 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Mar 28 12:30:02 volumio volumio[1390]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio
Mar 28 12:30:02 volumio volumio[1390]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio
Mar 28 12:30:02 volumio volumio[1390]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio
Mar 28 12:30:02 volumio volumio[1390]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio
Mar 28 12:30:02 volumio volumio[1390]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui
Mar 28 12:30:02 volumio volumio[1390]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller
Mar 28 12:30:02 volumio volumio[1390]: info: Preparing CD Folders
Mar 28 12:30:02 volumio volumio[1390]: info: Adding CD REST API Endpoints
Mar 28 12:30:02 volumio volumio[1390]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller
Mar 28 12:30:02 volumio volumio[1390]: info: Starting UDEV Watcher for CD
Mar 28 12:30:02 volumio volumio[1390]: info: Detecting CD presence with UDEV
Mar 28 12:30:02 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices
Mar 28 12:30:02 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Mar 28 12:30:02 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Mar 28 12:30:02 volumio sudo[2396]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Mar 28 12:30:02 volumio sudo[2396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Mar 28 12:30:02 volumio sudo[2396]: pam_unix(sudo:session): session closed for user root
Mar 28 12:30:03 volumio mpd[2398]: 2026-03-28T12:30:03 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Mar 28 12:30:03 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Mar 28 12:30:03 volumio sudo[2381]: pam_unix(sudo:session): session closed for user root
Mar 28 12:30:07 volumio volumio[1390]: warn: [cd-plugin] cdspeedctl: device or media not ready
Mar 28 12:30:07 volumio volumio[1390]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs
Mar 28 12:30:07 volumio volumio[1390]: info: Adding inputs REST Endpoints
Mar 28 12:30:07 volumio volumio[1390]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs
Mar 28 12:30:07 volumio volumio[1390]: info: Scanning Audio Inputs
Mar 28 12:30:07 volumio volumio[1390]: info: Checking against Known Cards name
Mar 28 12:30:07 volumio volumio[1390]: info: Adding Server instance for streaming
Mar 28 12:30:07 volumio volumio[1390]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio
Mar 28 12:30:07 volumio volumio[1390]: error: Hi Res Audio Failed Login: Missing Login Data
Mar 28 12:30:07 volumio volumio[1390]: info: Adding HIGHRESAUDIO REST API Endpoints
Mar 28 12:30:07 volumio volumio[1390]: info: Adding saveAccountData_hi_res_audio REST Endpoint for plugin: music_service/hi_res_audio
Mar 28 12:30:07 volumio volumio[1390]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal
Mar 28 12:30:07 volumio volumio[1390]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz
Mar 28 12:30:07 volumio volumio[1390]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect
Mar 28 12:30:07 volumio volumio[1390]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuzconnect
Mar 28 12:30:07 volumio volumio[1390]: info: Adding qc_getconfig REST Endpoint for plugin: music_service/qobuzconnect
Mar 28 12:30:07 volumio sudo[2427]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service
Mar 28 12:30:07 volumio sudo[2427]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 28 12:30:07 volumio volumio[1390]: info: QobuzConnect: Starting Qobuz Connect socket and service
Mar 28 12:30:08 volumio sudo[2427]: pam_unix(sudo:session): session closed for user root
Mar 28 12:30:08 volumio volumio[1390]: info: QobuzConnect: Opened /tmp/qbz-connect.socket socket, listening for connections
Mar 28 12:30:08 volumio volumio[1390]: info: Adding TIDAL REST API Endpoints
Mar 28 12:30:08 volumio volumio[1390]: info: Stopping AccessToken refresher cron for QOBUZ
Mar 28 12:30:08 volumio sudo[2434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl reset-failed qobuz-connect.service
Mar 28 12:30:08 volumio sudo[2434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 28 12:30:08 volumio sudo[2434]: pam_unix(sudo:session): session closed for user root
Mar 28 12:30:08 volumio sudo[2437]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart qobuz-connect.service
Mar 28 12:30:08 volumio sudo[2437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 28 12:30:08 volumio systemd[1]: Started qobuz-connect.service - Volumio Qobuz Connect Service.
Mar 28 12:30:08 volumio sudo[2437]: pam_unix(sudo:session): session closed for user root
Mar 28 12:30:08 volumio volumio[1390]: info: AccessToken refresher cron started for QOBUZ
Mar 28 12:30:08 volumio volumio[1390]: info: Adding QOBUZ REST API Endpoints
Mar 28 12:30:08 volumio volumio[1390]: info: MRS: Getting audio outputs on start
Mar 28 12:30:08 volumio volumio[1390]: info: MRS: Requesting all other devices output
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Mar 28 12:30:09 volumio volumio[1390]: info: CURURI: music-library/USB
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Mar 28 12:30:09 volumio volumio[1390]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Mar 28 12:30:09 volumio volumio[1390]: info: Received Get System Version
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 28 12:30:09 volumio volumio[1390]: info: Received Get System Info
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 28 12:30:09 volumio volumio[1390]: info: Discovery: Getting this device information
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:30:09 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 28 12:30:09 volumio volumio[1390]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on
Mar 28 12:30:09 volumio volumio[1390]: info: MPD Permissions set
Mar 28 12:30:09 volumio sudo[2441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service
Mar 28 12:30:09 volumio sudo[2441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 28 12:30:09 volumio volumio[1390]: info: Executing endpoint qc_getconfig
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: qobuzconnect , onGetConfig
Mar 28 12:30:09 volumio qobuz-connect[2439]: 20260328 12:30:09.625 [2439.2439] INFO SampleApp: Started connection to /tmp/qbz-connect.socket UNIX socket
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:30:09 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 28 12:30:09 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module.
Mar 28 12:30:09 volumio qobuz-connect[2439]: 20260328 12:30:09.749 [2439.2439] INFO VolumeManager: [0xe0a058]: Setting new playback volume: 75
Mar 28 12:30:09 volumio qobuz-connect[2439]: 20260328 12:30:09.749 [2439.2439] INFO VolumeManager: [0xe0a058]: Setting new mute state: 0
Mar 28 12:30:09 volumio qobuz-connect[2439]: 20260328 12:30:09.749 [2439.2439] INFO AudioStreamManager: [0xe09db0]: Setting new audio download buffer size: 1048576
Mar 28 12:30:09 volumio qobuz-connect[2439]: 20260328 12:30:09.749 [2439.2439] INFO QobuzConnect: [0xe0a920]: Client initialized!
Mar 28 12:30:09 volumio qobuz-connect[2439]: 20260328 12:30:09.749 [2439.2439] INFO SampleApp: Starting Avahi advertising, name: Volumio, service name: _qobuz-connect._tcp
Mar 28 12:30:09 volumio qobuz-connect[2439]: 20260328 12:30:09.769 [2439.2439] INFO LocalConfigManager: [0xe09ad8]: Starting Local Configuration server
Mar 28 12:30:09 volumio qobuz-connect[2439]: 20260328 12:30:09.769 [2439.2439] INFO SampleApp: Starting Local configuration server
Mar 28 12:30:09 volumio qobuz-connect[2439]: 20260328 12:30:09.770 [2439.2439] INFO SampleApp: Connected to UNIX socket client 0xdf4818
Mar 28 12:30:09 volumio qobuz-connect[2439]: 20260328 12:30:09.774 [2439.2439] INFO SampleApp: Playback volume changed: 75
Mar 28 12:30:09 volumio sudo[2441]: pam_unix(sudo:session): session closed for user root
Mar 28 12:30:09 volumio volumiobt[2451]: INFO [BTSTART] Ensuring Bluetooth directory exists...
Mar 28 12:30:09 volumio sudo[2452]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth
Mar 28 12:30:09 volumio sudo[2452]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 28 12:30:09 volumio sudo[2452]: pam_unix(sudo:session): session closed for user root
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 28 12:30:09 volumio sudo[2456]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth
Mar 28 12:30:09 volumio sudo[2456]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 28 12:30:09 volumio sudo[2456]: pam_unix(sudo:session): session closed for user root
Mar 28 12:30:09 volumio volumiobt[2460]: INFO [BTSTART] Powering on Bluetooth if needed...
Mar 28 12:30:09 volumio volumio[1390]: error: updateQueue error: null
Mar 28 12:30:09 volumio volumio[1390]: info: QobuzConnect: Qobuz Connect socket /tmp/qbz-connect.socket connected to client [object Object]
Mar 28 12:30:09 volumio volumio[1390]: info: QobuzConnect: QOBUZ Connect daemon connected
Mar 28 12:30:09 volumio bluetoothd[931]: Path / reserved for Adv Monitor app :1.32
Mar 28 12:30:09 volumio bluetoothd[931]: Adv Monitor app :1.32 disconnected from D-Bus
Mar 28 12:30:09 volumio volumiobt[2463]: INFO [BTSTART] Making Bluetooth discoverable and pairable...
Mar 28 12:30:09 volumio volumiobt[2464]: [176B blob data]
Mar 28 12:30:09 volumio volumiobt[2464]: [157B blob data]
Mar 28 12:30:09 volumio volumiobt[2464]: [157B blob data]
Mar 28 12:30:09 volumio volumiobt[2464]: [157B blob data]
Mar 28 12:30:09 volumio volumiobt[2464]: [113B blob data]
Mar 28 12:30:09 volumio volumiobt[2464]: [bluetoothctl]> discoverable on
Mar 28 12:30:09 volumio volumiobt[2464]: Warning: setting discoverable while discoverable-timeout not set(0) is not recommended
Mar 28 12:30:09 volumio volumiobt[2464]: [bluetoothctl]> pairable on
Mar 28 12:30:09 volumio volumiobt[2464]: [131B blob data]
Mar 28 12:30:09 volumio bluetoothd[931]: Path / reserved for Adv Monitor app :1.33
Mar 28 12:30:09 volumio bluetoothd[931]: Adv Monitor app :1.33 disconnected from D-Bus
Mar 28 12:30:09 volumio volumiobt[2464]: [bluetoothctl]>
Mar 28 12:30:09 volumio volumiobt[2465]: INFO [BTSTART] Registering Bluetooth agent...
Mar 28 12:30:09 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:30:09 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:30:10 volumio volumiobt[2466]: [NEW] Media /org/bluez/hci0
Mar 28 12:30:10 volumio volumiobt[2466]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb
Mar 28 12:30:10 volumio volumiobt[2466]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb
Mar 28 12:30:10 volumio volumiobt[2466]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb
Mar 28 12:30:10 volumio bluetoothd[931]: Path / reserved for Adv Monitor app :1.34
Mar 28 12:30:10 volumio bluetoothd[931]: Adv Monitor app :1.34 disconnected from D-Bus
Mar 28 12:30:10 volumio volumiobt[2467]: No agent is registered
Mar 28 12:30:10 volumio volumiobt[2467]: [NEW] Media /org/bluez/hci0
Mar 28 12:30:10 volumio volumiobt[2467]: SupportedUUIDs: 0000110a-0000-1000-8000-00805f9b34fb
Mar 28 12:30:10 volumio volumiobt[2467]: SupportedUUIDs: 0000110b-0000-1000-8000-00805f9b34fb
Mar 28 12:30:10 volumio volumiobt[2467]: SupportedUUIDs: 0000FDF0-0000-1000-8000-00805f9b34fb
Mar 28 12:30:10 volumio bluetoothd[931]: Adv Monitor app :1.35 disconnected from D-Bus
Mar 28 12:30:10 volumio volumio[1390]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully
Mar 28 12:30:10 volumio volumiobt[2468]: INFO [BTSTART] Agent registered successfully.
Mar 28 12:30:10 volumio volumiobt[2469]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)...
Mar 28 12:30:10 volumio volumio[1390]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart
Mar 28 12:30:10 volumio volumio[1390]: info: Starting Shairport Sync
Mar 28 12:30:10 volumio sudo[2472]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 28 12:30:10 volumio sudo[2472]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 28 12:30:10 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:30:10 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:30:10 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Mar 28 12:30:10 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Mar 28 12:30:10 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 28 12:30:10 volumio systemd[1]: shairport-sync.service: Consumed 1.543s CPU time.
Mar 28 12:30:10 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Mar 28 12:30:10 volumio volumiobt[2470]: 2026-03-28 12:30:10 a2dp-agent [INFO] Connecting to system D-Bus
Mar 28 12:30:10 volumio sudo[2472]: pam_unix(sudo:session): session closed for user root
Mar 28 12:30:10 volumio volumiobt[2470]: 2026-03-28 12:30:10 a2dp-agent [INFO] Connected to system D-Bus
Mar 28 12:30:10 volumio volumiobt[2470]: 2026-03-28 12:30:10 bluezutils [INFO] Found adapter at: /org/bluez/hci0
Mar 28 12:30:10 volumio volumiobt[2470]: 2026-03-28 12:30:10 a2dp-agent [INFO] Found Bluetooth adapter: /org/bluez/hci0
Mar 28 12:30:10 volumio volumiobt[2470]: 2026-03-28 12:30:10 a2dp-agent [INFO] Set DiscoverableTimeout to infinite
Mar 28 12:30:10 volumio volumiobt[2470]: 2026-03-28 12:30:10 a2dp-agent [INFO] Enabled Discoverable mode
Mar 28 12:30:10 volumio volumiobt[2470]: 2026-03-28 12:30:10 a2dp-agent [INFO] Agent registered at /local/a2dpagent
Mar 28 12:30:10 volumio volumiobt[2470]: 2026-03-28 12:30:10 a2dp-agent [INFO] Agent set as default
Mar 28 12:30:10 volumio volumiobt[2470]: 2026-03-28 12:30:10 a2dp-agent [INFO] A2DP agent running, waiting for connections...
Mar 28 12:30:11 volumio volumio[1390]: info: TidalConnect service stoped!
Mar 28 12:30:11 volumio volumio[1390]: info: Shairport-Sync Started
Mar 28 12:30:11 volumio volumio[1390]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect
Mar 28 12:30:11 volumio volumio[1390]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect
Mar 28 12:30:11 volumio sudo[2498]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service
Mar 28 12:30:11 volumio sudo[2498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 28 12:30:11 volumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service.
Mar 28 12:30:11 volumio sudo[2498]: pam_unix(sudo:session): session closed for user root
Mar 28 12:30:12 volumio volumio[1390]: info: Executing endpoint tc_getconfig
Mar 28 12:30:12 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig
Mar 28 12:30:12 volumio vtcs[2501]: STARTING TidalConnect services, version: 1.6.1
Mar 28 12:30:12 volumio vtcs[2501]: STARTED TidalConnect services.
Mar 28 12:30:12 volumio volumio[1390]: info: Executing endpoint tc_connect
Mar 28 12:30:12 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect
Mar 28 12:30:12 volumio volumio[1390]: info: Connecting to TidalConnect
Mar 28 12:30:12 volumio volumio[1390]: info: CoreCommandRouter::servicePushState
Mar 28 12:30:12 volumio volumio[1390]: info: CoreStateMachine::pushState
Mar 28 12:30:12 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:30:12 volumio volumio[1390]: info: CoreCommandRouter::volumioPushState
Mar 28 12:30:12 volumio volumio[1390]: info: MRS: Pushing multiroomSync output update for this device
Mar 28 12:30:12 volumio volumio[1390]: info: MRS: Pushing multiroomSync output
Mar 28 12:30:12 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:30:12 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:30:12 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:30:12 volumio volumio[1390]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect
Mar 28 12:30:12 volumio volumio[1390]: info: CoreCommandRouter::servicePushState
Mar 28 12:30:12 volumio volumio[1390]: info: CoreStateMachine::pushState
Mar 28 12:30:12 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:30:12 volumio volumio[1390]: info: CoreCommandRouter::volumioPushState
Mar 28 12:30:12 volumio volumio[1390]: info: MRS: Pushing multiroomSync output update for this device
Mar 28 12:30:12 volumio volumio[1390]: info: MRS: Pushing multiroomSync output
Mar 28 12:30:12 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:30:12 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:30:12 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:30:12 volumio volumio[1390]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received tidalconnect
Mar 28 12:30:14 volumio volumio[1390]: info: TidalConnect service started!
Mar 28 12:30:14 volumio volumio[1390]: [Metrics] CommandRouter: 76s 13.52ms
Mar 28 12:30:14 volumio volumio[1390]: info: CoreCommandRouter::volumiosetStartupVolume
Mar 28 12:30:14 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 28 12:30:14 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 28 12:30:14 volumio volumio[1390]: info: CoreCommandRouter::Close All Modals sent
Mar 28 12:30:14 volumio volumio[1390]: info: CoreCommandRouter::Close All Modals sent
Mar 28 12:30:15 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Mar 28 12:30:15 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Mar 28 12:30:15 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Mar 28 12:30:17 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Mar 28 12:30:17 volumio volumio[1390]: info: CURURI: artists://
Mar 28 12:30:18 volumio volumio[1390]: info: Preload queue cleared
Mar 28 12:30:21 volumio volumio[1390]: info: BOOT COMPLETED
Mar 28 12:30:35 volumio dhcpcd[979]: wlan0: carrier lost - roaming
Mar 28 12:30:35 volumio dhcpcd[979]: wlan0: changing route to 192.168.1.0/24
Mar 28 12:30:35 volumio wpa_supplicant[1353]: wlan0: Associated with 08:16:05:a9:7e:11
Mar 28 12:30:35 volumio wpa_supplicant[1353]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Mar 28 12:30:35 volumio dhcpcd[979]: wlan0: changing default route via 192.168.1.1
Mar 28 12:30:35 volumio wpa_supplicant[1353]: wlan0: WPA: Key negotiation completed with 08:16:05:a9:7e:11 [PTK=CCMP GTK=CCMP]
Mar 28 12:30:35 volumio wpa_supplicant[1353]: wlan0: CTRL-EVENT-CONNECTED - Connection to 08:16:05:a9:7e:11 completed [id=0 id_str=]
Mar 28 12:30:35 volumio dhcpcd[979]: wlan0: carrier acquired
Mar 28 12:30:35 volumio dhcpcd[979]: wlan0: IAID dd:4a:a4:b1
Mar 28 12:30:36 volumio dhcpcd[979]: wlan0: soliciting an IPv6 router
Mar 28 12:30:36 volumio volumio[1390]: info: Received Get System Info
Mar 28 12:30:36 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 28 12:30:36 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 28 12:30:36 volumio volumio[1390]: info: Discovery: Getting this device information
Mar 28 12:30:36 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:30:36 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:30:36 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 28 12:30:36 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Mar 28 12:30:36 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Mar 28 12:30:36 volumio dhcpcd[979]: wlan0: soliciting a DHCP lease
Mar 28 12:30:37 volumio dhcpcd[979]: wlan0: offered 192.168.1.50 from 192.168.1.1
Mar 28 12:30:37 volumio dhcpcd[979]: wlan0: leased 192.168.1.50 for 86400 seconds
Mar 28 12:30:37 volumio dhcpcd[979]: wlan0: changing route to 192.168.1.0/24
Mar 28 12:30:37 volumio dhcpcd[979]: wlan0: changing default route via 192.168.1.1
Mar 28 12:30:37 volumio systemd[1]: Stopped target ip-changed@wlan0.target - IP Address changed on wlan0.
Mar 28 12:30:37 volumio systemd[1]: Stopping ip-changed@wlan0.target - IP Address changed on wlan0...
Mar 28 12:30:37 volumio systemd[1]: welcome.service: Deactivated successfully.
Mar 28 12:30:37 volumio systemd[1]: Stopped welcome.service - Show a welcome message on console.
Mar 28 12:30:37 volumio systemd[1]: Stopping welcome.service - Show a welcome message on console...
Mar 28 12:30:37 volumio systemd[1]: Starting welcome.service - Show a welcome message on console...
Mar 28 12:30:37 volumio welcome[2621]: Resolved ip:[1] 192.168.1.50
Mar 28 12:30:37 volumio systemd[1]: Finished welcome.service - Show a welcome message on console.
Mar 28 12:30:37 volumio systemd[1]: Reached target ip-changed@wlan0.target - IP Address changed on wlan0.
Mar 28 12:30:37 volumio volumio5-onboarding[1781]: time=2026-03-28T12:30:37.440+01:00 level=INFO msg="service successfully established" component=discovery/localnet
Mar 28 12:30:37 volumio volumio[1390]: info: Received Get System Info
Mar 28 12:30:37 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 28 12:30:37 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 28 12:30:37 volumio volumio[1390]: info: Discovery: Getting this device information
Mar 28 12:30:37 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:30:37 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:30:37 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 28 12:30:37 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Mar 28 12:30:37 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Mar 28 12:30:37 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 28 12:30:38 volumio volumio[1390]: info: Received Get System Info
Mar 28 12:30:38 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 28 12:30:38 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 28 12:30:38 volumio volumio[1390]: info: Discovery: Getting this device information
Mar 28 12:30:38 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:30:38 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:30:38 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 28 12:30:38 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Mar 28 12:30:38 volumio volumio[1390]: info: CURURI: artists://
Mar 28 12:30:38 volumio volumio[1390]: info: Preload queue cleared
Mar 28 12:30:38 volumio volumio5-onboarding[1781]: time=2026-03-28T12:30:38.673+01:00 level=INFO msg="service successfully established" component=discovery/localnet
Mar 28 12:31:02 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:31:02 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:04 volumio volumio[1390]: info: Executing endpoint metavolumio
Mar 28 12:31:04 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Mar 28 12:31:04 volumio volumio[1390]: info: Executing endpoint metavolumio
Mar 28 12:31:04 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Mar 28 12:31:04 volumio volumio[1390]: info: Executing endpoint metavolumio
Mar 28 12:31:04 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Mar 28 12:31:10 volumio kernel: usb 2-1: USB disconnect, device number 2
Mar 28 12:31:10 volumio kernel: usb 2-1: new SuperSpeed USB device number 3 using xhci_hcd
Mar 28 12:31:10 volumio kernel: usb 2-1: New USB device found, idVendor=0781, idProduct=55b1, bcdDevice= 1.10
Mar 28 12:31:10 volumio kernel: usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Mar 28 12:31:10 volumio kernel: usb 2-1: Product: SanDisk 3.2 Gen1
Mar 28 12:31:10 volumio kernel: usb 2-1: Manufacturer: SanDisk
Mar 28 12:31:10 volumio kernel: usb 2-1: SerialNumber: A200378B8A060F17
Mar 28 12:31:10 volumio kernel: usb-storage 2-1:1.0: USB Mass Storage device detected
Mar 28 12:31:10 volumio kernel: scsi host1: usb-storage 2-1:1.0
Mar 28 12:31:10 volumio volumio[1390]: info: Partition removed: {"syspath":"/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-1/2-1:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","ACTION":"remove","CURRENT_TAGS":":systemd:","DEVLINKS":"/dev/disk/by-label/USBMusic /dev/disk/by-partuuid/c3072e18-01 /dev/disk/by-uuid/6539-06D5 /dev/disk/by-path/platform-fd500000.pcie-pci-0000:01:00.0-usb-0:1:1.0-scsi-0:0:0:0-part1 /dev/disk/by-id/usb-SanDisk_SanDisk_3.2_Gen1_A200378B8A060F17-0:0-part1","DEVNAME":"/dev/sda1","DEVPATH":"/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-1/2-1:1.0/host0/target0:0:0/0:0:0:0/block/sda/sda1","DEVTYPE":"partition","DISKSEQ":"26","ID_BUS":"usb","ID_FS_LABEL":"USBMusic","ID_FS_LABEL_ENC":"USBMusic","ID_FS_TYPE":"exfat","ID_FS_USAGE":"filesystem","ID_FS_UUID":"6539-06D5","ID_FS_UUID_ENC":"6539-06D5","ID_FS_VERSION":"1.0","ID_INSTANCE":"0:0","ID_MODEL":"SanDisk_3.2_Gen1","ID_MODEL_ENC":"SanDisk\\x203.2\\x20Gen1","ID_MODEL_ID":"55b1","ID_PART_ENTRY_DISK":"8:0","ID_PART_ENTRY_NUMBER":"1","ID_PART_ENTRY_OFFSET":"7552","ID_PART_ENTRY_SCHEME":"dos","ID_PART_ENTRY_SIZE":"244449920","ID_PART_ENTRY_TYPE":"0x7","ID_PART_ENTRY_UUID":"c3072e18-01","ID_PART_TABLE_TYPE":"dos","ID_PART_TABLE_UUID":"c3072e18","ID_PATH":"platform-fd500000.pcie-pci-0000:01:00.0-usb-0:1:1.0-scsi-0:0:0:0","ID_PATH_TAG":"platform-fd500000_pcie-pci-0000_01_00_0-usb-0_1_1_0-scsi-0_0_0_0","ID_REVISION":"DL17","ID_SERIAL":"SanDisk_SanDisk_3.2_Gen1_A200378B8A060F17-0:0","ID_SERIAL_SHORT":"A200378B8A060F17","ID_TYPE":"disk","ID_USB_DRIVER":"usb-storage","ID_USB_INSTANCE":"0:0","ID_USB_INTERFACES":":080650:","ID_USB_INTERFACE_NUM":"00","ID_USB_MODEL":"SanDisk_3.2_Gen1","ID_USB_MODEL_ENC":"SanDisk\\x203.2\\x20Gen1","ID_USB_MODEL_ID":"55b1","ID_USB_REVISION":"DL17","ID_USB_SERIAL":"SanDisk_SanDisk_3.2_Gen1_A200378B8A060F17-0:0","ID_USB_SERIAL_SHORT":"A200378B8A060F17","ID_USB_TYPE":"disk","ID_USB_VENDOR":"SanDisk","ID_USB_VENDOR_ENC":"SanDisk\\x20","ID_USB_VENDOR_ID":"0781","ID_VENDOR":"SanDisk","ID_VENDOR_ENC":"SanDisk\\x20","ID_VENDOR_ID":"0781","MAJOR":"8","MINOR":"1","PARTN":"1","SEQNUM":"2891","SUBSYSTEM":"block","TAGS":":systemd:","USEC_INITIALIZED":"4162753"}
Mar 28 12:31:11 volumio sudo[2735]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/umount -f /dev/sda1
Mar 28 12:31:11 volumio sudo[2735]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 28 12:31:11 volumio systemd[1]: media-USBMusic.mount: Deactivated successfully.
Mar 28 12:31:11 volumio sudo[2735]: pam_unix(sudo:session): session closed for user root
Mar 28 12:31:11 volumio kernel: scsi 1:0:0:0: Direct-Access SanDisk SanDisk 3.2 Gen1 DL17 PQ: 0 ANSI: 6
Mar 28 12:31:11 volumio kernel: sd 1:0:0:0: Attached scsi generic sg0 type 0
Mar 28 12:31:11 volumio kernel: sd 1:0:0:0: [sda] 244457472 512-byte logical blocks: (125 GB/117 GiB)
Mar 28 12:31:11 volumio kernel: sd 1:0:0:0: [sda] Write Protect is off
Mar 28 12:31:11 volumio kernel: sd 1:0:0:0: [sda] Mode Sense: 45 00 00 00
Mar 28 12:31:11 volumio kernel: sd 1:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
Mar 28 12:31:12 volumio kernel: sda: sda1
Mar 28 12:31:12 volumio kernel: sd 1:0:0:0: [sda] Attached SCSI removable disk
Mar 28 12:31:12 volumio volumio[1390]: info: Mounting Device USBMusic
Mar 28 12:31:12 volumio kernel: usb 1-1.3: new high-speed USB device number 4 using xhci_hcd
Mar 28 12:31:12 volumio sudo[2744]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/USBMusic -o noatime
Mar 28 12:31:12 volumio sudo[2744]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 28 12:31:12 volumio kernel: usb 1-1.3: New USB device found, idVendor=0951, idProduct=1666, bcdDevice= 1.10
Mar 28 12:31:12 volumio kernel: usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Mar 28 12:31:12 volumio kernel: usb 1-1.3: Product: DataTraveler 3.0
Mar 28 12:31:12 volumio kernel: usb 1-1.3: Manufacturer: Kingston
Mar 28 12:31:12 volumio kernel: usb 1-1.3: SerialNumber: C87F54C69E1AE951C9000229
Mar 28 12:31:12 volumio kernel: usb-storage 1-1.3:1.0: USB Mass Storage device detected
Mar 28 12:31:12 volumio kernel: scsi host0: usb-storage 1-1.3:1.0
Mar 28 12:31:12 volumio sudo[2744]: pam_unix(sudo:session): session closed for user root
Mar 28 12:31:13 volumio kernel: scsi 0:0:0:0: Direct-Access Kingston DataTraveler 3.0 PMAP PQ: 0 ANSI: 6
Mar 28 12:31:13 volumio kernel: sd 0:0:0:0: Attached scsi generic sg1 type 0
Mar 28 12:31:13 volumio kernel: sd 0:0:0:0: [sdb] 484442112 512-byte logical blocks: (248 GB/231 GiB)
Mar 28 12:31:13 volumio kernel: sd 0:0:0:0: [sdb] Write Protect is off
Mar 28 12:31:13 volumio kernel: sd 0:0:0:0: [sdb] Mode Sense: 45 00 00 00
Mar 28 12:31:13 volumio kernel: sd 0:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
Mar 28 12:31:13 volumio kernel: sdb: sdb1
Mar 28 12:31:13 volumio kernel: sd 0:0:0:0: [sdb] Attached SCSI removable disk
Mar 28 12:31:14 volumio volumio[1390]: info: Mounting Device KINGSTON
Mar 28 12:31:14 volumio sudo[2759]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sdb1 /mnt/USB/KINGSTON -o noatime,dmask=0000,fmask=0000,iocharset=utf8
Mar 28 12:31:14 volumio sudo[2759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 28 12:31:14 volumio kernel: FAT-fs (sdb1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive!
Mar 28 12:31:14 volumio sudo[2759]: pam_unix(sudo:session): session closed for user root
Mar 28 12:31:15 volumio volumio[1390]: info: Scanning new location : "USB/KINGSTON"
Mar 28 12:31:15 volumio volumio[1390]: verbose: ControllerMpd::sendMpdCommand status
Mar 28 12:31:15 volumio volumio[1390]: info:
Mar 28 12:31:15 volumio volumio[1390]: ---------------------------- MPD announces state update: update
Mar 28 12:31:15 volumio volumio[1390]: info: ControllerMpd::getState
Mar 28 12:31:15 volumio volumio[1390]: verbose: ControllerMpd::sendMpdCommand status
Mar 28 12:31:15 volumio volumio[1390]: info: sendMpdCommand status took 64 milliseconds
Mar 28 12:31:15 volumio volumio[1390]: info: sendMpdCommand status took 12 milliseconds
Mar 28 12:31:15 volumio volumio[1390]: verbose: ControllerMpd::parseState
Mar 28 12:31:15 volumio volumio[1390]: info: Command Router : Notfying DB Updatetrue
Mar 28 12:31:15 volumio volumio[1390]: verbose: ControllerMpd::parseState
Mar 28 12:31:15 volumio volumio[1390]: info: ControllerMpd::pushState
Mar 28 12:31:15 volumio volumio[1390]: info: CoreCommandRouter::servicePushState
Mar 28 12:31:15 volumio volumio[1390]: info: CoreStateMachine::pushState
Mar 28 12:31:15 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:15 volumio volumio[1390]: info: CoreCommandRouter::volumioPushState
Mar 28 12:31:15 volumio volumio[1390]: info: MRS: Pushing multiroomSync output update for this device
Mar 28 12:31:15 volumio volumio[1390]: info: MRS: Pushing multiroomSync output
Mar 28 12:31:15 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:31:15 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:15 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:15 volumio volumio[1390]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null}
Mar 28 12:31:15 volumio volumio[1390]: verbose: CURRENT POSITION 0
Mar 28 12:31:15 volumio volumio[1390]: info: CoreStateMachine::syncState stateService stop
Mar 28 12:31:15 volumio volumio[1390]: info: CoreStateMachine::syncState currentStatus stop
Mar 28 12:31:15 volumio volumio[1390]: info: CoreStateMachine::pushState
Mar 28 12:31:15 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:15 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 28 12:31:15 volumio volumio[1390]: info: CoreCommandRouter::volumioPushState
Mar 28 12:31:15 volumio volumio[1390]: info: MRS: Pushing multiroomSync output update for this device
Mar 28 12:31:15 volumio volumio[1390]: info: MRS: Pushing multiroomSync output
Mar 28 12:31:15 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:31:15 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:15 volumio volumio[1390]: info: No code
Mar 28 12:31:15 volumio volumio[1390]: info: CoreStateMachine::pushState
Mar 28 12:31:15 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:15 volumio volumio[1390]: info: CoreCommandRouter::volumioPushState
Mar 28 12:31:15 volumio volumio[1390]: info: MRS: Pushing multiroomSync output update for this device
Mar 28 12:31:15 volumio volumio[1390]: info: MRS: Pushing multiroomSync output
Mar 28 12:31:15 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:31:15 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:16 volumio volumio[1390]: info: ------------------------------ 1139ms
Mar 28 12:31:16 volumio volumio[1390]: info: TEST: Here we shall have deleted mounted folder: /mnt/USB/USBMusic
Mar 28 12:31:16 volumio volumio[1390]: info: Scanning removed location : "USB/USBMusic"
Mar 28 12:31:17 volumio volumio[1390]: info: MPD Database updated - AlbumList cache refreshed
Mar 28 12:31:17 volumio volumio[1390]: info:
Mar 28 12:31:17 volumio volumio[1390]: ---------------------------- MPD announces state update: database
Mar 28 12:31:17 volumio volumio[1390]: verbose: ControllerMpd::sendMpdCommand status
Mar 28 12:31:17 volumio volumio[1390]: info:
Mar 28 12:31:17 volumio volumio[1390]: ---------------------------- MPD announces state update: update
Mar 28 12:31:17 volumio volumio[1390]: info: ControllerMpd::getState
Mar 28 12:31:17 volumio volumio[1390]: verbose: ControllerMpd::sendMpdCommand status
Mar 28 12:31:17 volumio volumio[1390]: info: ControllerMpd::getState
Mar 28 12:31:17 volumio volumio[1390]: verbose: ControllerMpd::sendMpdCommand status
Mar 28 12:31:17 volumio volumio[1390]: info: sendMpdCommand status took 308 milliseconds
Mar 28 12:31:17 volumio volumio[1390]: info: sendMpdCommand status took 305 milliseconds
Mar 28 12:31:17 volumio volumio[1390]: info: sendMpdCommand status took 306 milliseconds
Mar 28 12:31:17 volumio volumio[1390]: verbose: ControllerMpd::parseState
Mar 28 12:31:17 volumio volumio[1390]: info: Command Router : Notfying DB Updatetrue
Mar 28 12:31:17 volumio volumio[1390]: info: CoreCommandRouter::Close All Modals sent
Mar 28 12:31:17 volumio volumio[1390]: verbose: ControllerMpd::parseState
Mar 28 12:31:17 volumio volumio[1390]: verbose: ControllerMpd::parseState
Mar 28 12:31:17 volumio volumio[1390]: info: ControllerMpd::pushState
Mar 28 12:31:17 volumio volumio[1390]: info: CoreCommandRouter::servicePushState
Mar 28 12:31:17 volumio volumio[1390]: info: CoreStateMachine::pushState
Mar 28 12:31:17 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:17 volumio volumio[1390]: info: CoreCommandRouter::volumioPushState
Mar 28 12:31:17 volumio volumio[1390]: info: MRS: Pushing multiroomSync output update for this device
Mar 28 12:31:17 volumio volumio[1390]: info: MRS: Pushing multiroomSync output
Mar 28 12:31:18 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:31:18 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:18 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:18 volumio volumio[1390]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null}
Mar 28 12:31:18 volumio volumio[1390]: verbose: CURRENT POSITION 0
Mar 28 12:31:18 volumio volumio[1390]: info: CoreStateMachine::syncState stateService stop
Mar 28 12:31:18 volumio volumio[1390]: info: CoreStateMachine::syncState currentStatus stop
Mar 28 12:31:18 volumio volumio[1390]: info: CoreStateMachine::pushState
Mar 28 12:31:18 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:18 volumio volumio[1390]: info: CoreCommandRouter::volumioPushState
Mar 28 12:31:18 volumio volumio[1390]: info: MRS: Pushing multiroomSync output update for this device
Mar 28 12:31:18 volumio volumio[1390]: info: MRS: Pushing multiroomSync output
Mar 28 12:31:18 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:31:18 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:18 volumio volumio[1390]: info: No code
Mar 28 12:31:18 volumio volumio[1390]: info: CoreStateMachine::pushState
Mar 28 12:31:18 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:18 volumio volumio[1390]: info: CoreCommandRouter::volumioPushState
Mar 28 12:31:18 volumio volumio[1390]: info: MRS: Pushing multiroomSync output update for this device
Mar 28 12:31:18 volumio volumio[1390]: info: MRS: Pushing multiroomSync output
Mar 28 12:31:18 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:31:18 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:18 volumio volumio[1390]: info: ControllerMpd::pushState
Mar 28 12:31:18 volumio volumio[1390]: info: CoreCommandRouter::servicePushState
Mar 28 12:31:18 volumio volumio[1390]: info: CoreStateMachine::pushState
Mar 28 12:31:18 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:18 volumio volumio[1390]: info: CoreCommandRouter::volumioPushState
Mar 28 12:31:18 volumio volumio[1390]: info: MRS: Pushing multiroomSync output update for this device
Mar 28 12:31:18 volumio volumio[1390]: info: MRS: Pushing multiroomSync output
Mar 28 12:31:18 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:31:18 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:18 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:18 volumio volumio[1390]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null}
Mar 28 12:31:18 volumio volumio[1390]: verbose: CURRENT POSITION 0
Mar 28 12:31:18 volumio volumio[1390]: info: CoreStateMachine::syncState stateService stop
Mar 28 12:31:18 volumio volumio[1390]: info: CoreStateMachine::syncState currentStatus stop
Mar 28 12:31:18 volumio volumio[1390]: info: CoreStateMachine::pushState
Mar 28 12:31:18 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:18 volumio volumio[1390]: info: CoreCommandRouter::volumioPushState
Mar 28 12:31:18 volumio volumio[1390]: info: MRS: Pushing multiroomSync output update for this device
Mar 28 12:31:18 volumio volumio[1390]: info: MRS: Pushing multiroomSync output
Mar 28 12:31:18 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:31:18 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:18 volumio volumio[1390]: info: No code
Mar 28 12:31:18 volumio volumio[1390]: info: CoreStateMachine::pushState
Mar 28 12:31:18 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:18 volumio volumio[1390]: info: CoreCommandRouter::volumioPushState
Mar 28 12:31:18 volumio volumio[1390]: info: MRS: Pushing multiroomSync output update for this device
Mar 28 12:31:18 volumio volumio[1390]: info: MRS: Pushing multiroomSync output
Mar 28 12:31:18 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:31:18 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:18 volumio volumio[1390]: info: ------------------------------ 1642ms
Mar 28 12:31:18 volumio volumio[1390]: info: ------------------------------ 1642ms
Mar 28 12:31:18 volumio volumio[1390]: verbose: ControllerMpd::sendMpdCommand status
Mar 28 12:31:18 volumio volumio[1390]: info:
Mar 28 12:31:18 volumio volumio[1390]: ---------------------------- MPD announces state update: update
Mar 28 12:31:18 volumio volumio[1390]: info: ControllerMpd::getState
Mar 28 12:31:18 volumio volumio[1390]: verbose: ControllerMpd::sendMpdCommand status
Mar 28 12:31:19 volumio volumio[1390]: info: sendMpdCommand status took 519 milliseconds
Mar 28 12:31:19 volumio volumio[1390]: info: sendMpdCommand status took 516 milliseconds
Mar 28 12:31:19 volumio volumio[1390]: verbose: ControllerMpd::parseState
Mar 28 12:31:19 volumio volumio[1390]: info: Command Router : Notfying DB Updatefalse
Mar 28 12:31:19 volumio volumio[1390]: info: CoreCommandRouter::Close All Modals sent
Mar 28 12:31:19 volumio volumio[1390]: verbose: ControllerMpd::parseState
Mar 28 12:31:19 volumio volumio[1390]: info: ControllerMpd::pushState
Mar 28 12:31:19 volumio volumio[1390]: info: CoreCommandRouter::servicePushState
Mar 28 12:31:19 volumio volumio[1390]: info: CoreStateMachine::pushState
Mar 28 12:31:19 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:19 volumio volumio[1390]: info: CoreCommandRouter::volumioPushState
Mar 28 12:31:19 volumio volumio[1390]: info: MRS: Pushing multiroomSync output update for this device
Mar 28 12:31:19 volumio volumio[1390]: info: MRS: Pushing multiroomSync output
Mar 28 12:31:19 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:31:19 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:19 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:19 volumio volumio[1390]: 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}
Mar 28 12:31:19 volumio volumio[1390]: verbose: CURRENT POSITION 0
Mar 28 12:31:19 volumio volumio[1390]: info: CoreStateMachine::syncState stateService stop
Mar 28 12:31:19 volumio volumio[1390]: info: CoreStateMachine::syncState currentStatus stop
Mar 28 12:31:19 volumio volumio[1390]: info: CoreStateMachine::pushState
Mar 28 12:31:19 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:19 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 28 12:31:19 volumio volumio[1390]: info: CoreCommandRouter::volumioPushState
Mar 28 12:31:19 volumio volumio[1390]: info: MRS: Pushing multiroomSync output update for this device
Mar 28 12:31:19 volumio volumio[1390]: info: MRS: Pushing multiroomSync output
Mar 28 12:31:19 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:31:19 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:19 volumio volumio[1390]: info: No code
Mar 28 12:31:19 volumio volumio[1390]: info: CoreStateMachine::pushState
Mar 28 12:31:19 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:19 volumio volumio[1390]: info: CoreCommandRouter::volumioPushState
Mar 28 12:31:19 volumio volumio[1390]: info: MRS: Pushing multiroomSync output update for this device
Mar 28 12:31:19 volumio volumio[1390]: info: MRS: Pushing multiroomSync output
Mar 28 12:31:19 volumio volumio[1390]: info: CoreCommandRouter::volumioGetState
Mar 28 12:31:19 volumio volumio[1390]: info: CorePlayQueue::getTrack 0
Mar 28 12:31:20 volumio volumio[1390]: info: ------------------------------ 1186ms
Mar 28 12:31:26 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Mar 28 12:31:26 volumio volumio[1390]: info: CURURI: artists://
Mar 28 12:31:26 volumio volumio[1390]: info: Preload queue cleared
Mar 28 12:31:39 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Mar 28 12:31:39 volumio volumio[1390]: info: CURURI: artists://Pat%20Metheny%20Group
Mar 28 12:31:40 volumio volumio[1390]: info: Preload queue cleared
Mar 28 12:31:40 volumio volumio[1390]: info: Preload queue cleared
Mar 28 12:31:40 volumio volumio[1390]: info: Preloading song: music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/01 Imaginary Day.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Preloading song: music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/02 Follow Me.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Preloading song: music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/03 Into The Dream.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Preloading song: music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/04 A Story Within A Story.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Preloading song: music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/05 The Heat Of The Day.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Preloading song: music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/06 Across The Sky.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Preloading song: music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/07 The Roots Of Coincidence.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Preloading song: music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/08 Too Soon Tomorrow.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Preloading song: music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/09 The Awakening.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Exploding uri music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/01 Imaginary Day.m4a in service mpd
Mar 28 12:31:40 volumio volumio[1390]: info: ALBUMART /albumart?cacheid=490&web=Pat%20Metheny%20Group/Imaginary%20Day/extralarge&path=%2Fmnt%2FUSB%2FKINGSTON%2FPat%20Metheny%20Group%2FImaginary%20Day%2F01%20Imaginary%20Day.m4a&metadata=false
Mar 28 12:31:40 volumio volumio[1390]: info: URI /mnt/USB/KINGSTON/Pat Metheny Group/Imaginary Day/01 Imaginary Day.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Exploding uri music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/02 Follow Me.m4a in service mpd
Mar 28 12:31:40 volumio volumio[1390]: info: ALBUMART /albumart?cacheid=490&web=Pat%20Metheny%20Group/Imaginary%20Day/extralarge&path=%2Fmnt%2FUSB%2FKINGSTON%2FPat%20Metheny%20Group%2FImaginary%20Day%2F02%20Follow%20Me.m4a&metadata=false
Mar 28 12:31:40 volumio volumio[1390]: info: URI /mnt/USB/KINGSTON/Pat Metheny Group/Imaginary Day/02 Follow Me.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Exploding uri music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/03 Into The Dream.m4a in service mpd
Mar 28 12:31:40 volumio volumio[1390]: info: ALBUMART /albumart?cacheid=490&web=Pat%20Metheny%20Group/Imaginary%20Day/extralarge&path=%2Fmnt%2FUSB%2FKINGSTON%2FPat%20Metheny%20Group%2FImaginary%20Day%2F03%20Into%20The%20Dream.m4a&metadata=false
Mar 28 12:31:40 volumio volumio[1390]: info: URI /mnt/USB/KINGSTON/Pat Metheny Group/Imaginary Day/03 Into The Dream.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Exploding uri music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/04 A Story Within A Story.m4a in service mpd
Mar 28 12:31:40 volumio volumio[1390]: info: ALBUMART /albumart?cacheid=490&web=Pat%20Metheny%20Group/Imaginary%20Day/extralarge&path=%2Fmnt%2FUSB%2FKINGSTON%2FPat%20Metheny%20Group%2FImaginary%20Day%2F04%20A%20Story%20Within%20A%20Story.m4a&metadata=false
Mar 28 12:31:40 volumio volumio[1390]: info: URI /mnt/USB/KINGSTON/Pat Metheny Group/Imaginary Day/04 A Story Within A Story.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Exploding uri music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/05 The Heat Of The Day.m4a in service mpd
Mar 28 12:31:40 volumio volumio[1390]: info: ALBUMART /albumart?cacheid=490&web=Pat%20Metheny%20Group/Imaginary%20Day/extralarge&path=%2Fmnt%2FUSB%2FKINGSTON%2FPat%20Metheny%20Group%2FImaginary%20Day%2F05%20The%20Heat%20Of%20The%20Day.m4a&metadata=false
Mar 28 12:31:40 volumio volumio[1390]: info: URI /mnt/USB/KINGSTON/Pat Metheny Group/Imaginary Day/05 The Heat Of The Day.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Exploding uri music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/06 Across The Sky.m4a in service mpd
Mar 28 12:31:40 volumio volumio[1390]: info: ALBUMART /albumart?cacheid=490&web=Pat%20Metheny%20Group/Imaginary%20Day/extralarge&path=%2Fmnt%2FUSB%2FKINGSTON%2FPat%20Metheny%20Group%2FImaginary%20Day%2F06%20Across%20The%20Sky.m4a&metadata=false
Mar 28 12:31:40 volumio volumio[1390]: info: URI /mnt/USB/KINGSTON/Pat Metheny Group/Imaginary Day/06 Across The Sky.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Exploding uri music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/07 The Roots Of Coincidence.m4a in service mpd
Mar 28 12:31:40 volumio volumio[1390]: info: ALBUMART /albumart?cacheid=490&web=Pat%20Metheny%20Group/Imaginary%20Day/extralarge&path=%2Fmnt%2FUSB%2FKINGSTON%2FPat%20Metheny%20Group%2FImaginary%20Day%2F07%20The%20Roots%20Of%20Coincidence.m4a&metadata=false
Mar 28 12:31:40 volumio volumio[1390]: info: URI /mnt/USB/KINGSTON/Pat Metheny Group/Imaginary Day/07 The Roots Of Coincidence.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Exploding uri music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/08 Too Soon Tomorrow.m4a in service mpd
Mar 28 12:31:40 volumio volumio[1390]: info: ALBUMART /albumart?cacheid=490&web=Pat%20Metheny%20Group/Imaginary%20Day/extralarge&path=%2Fmnt%2FUSB%2FKINGSTON%2FPat%20Metheny%20Group%2FImaginary%20Day%2F08%20Too%20Soon%20Tomorrow.m4a&metadata=false
Mar 28 12:31:40 volumio volumio[1390]: info: URI /mnt/USB/KINGSTON/Pat Metheny Group/Imaginary Day/08 Too Soon Tomorrow.m4a
Mar 28 12:31:40 volumio volumio[1390]: info: Exploding uri music-library/USB/KINGSTON/Pat Metheny Group/Imaginary Day/09 The Awakening.m4a in service mpd
Mar 28 12:31:40 volumio volumio[1390]: info: ALBUMART /albumart?cacheid=490&web=Pat%20Metheny%20Group/Imaginary%20Day/extralarge&path=%2Fmnt%2FUSB%2FKINGSTON%2FPat%20Metheny%20Group%2FImaginary%20Day%2F09%20The%20Awakening.m4a&metadata=false
Mar 28 12:31:40 volumio volumio[1390]: info: URI /mnt/USB/KINGSTON/Pat Metheny Group/Imaginary Day/09 The Awakening.m4a
Mar 28 12:31:41 volumio volumio[1390]: info: Executing endpoint getSimilarArtists
Mar 28 12:31:41 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists
Mar 28 12:31:41 volumio volumio[1390]: info: Executing endpoint metavolumio
Mar 28 12:31:41 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Mar 28 12:31:41 volumio volumio[1390]: info: Executing endpoint metavolumio
Mar 28 12:31:41 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio
Mar 28 12:31:41 volumio volumio[1390]: info: Executing endpoint getSimilarArtists
Mar 28 12:31:41 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists
Mar 28 12:31:43 volumio volumio[1390]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri
Mar 28 12:31:43 volumio volumio[1390]: info: CURURI: artists://Pat%20Metheny%20Group/Imaginary%20Day
Mar 28 12:31:43 volumio volumio[1390]: info: Preload queue cleared
Mar 28 12:31:43 volumio volumio[1390]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 28 12:31:43 volumio volumio[1390]: TypeError: Cannot read properties of null (reading 'slice')
Mar 28 12:31:43 volumio volumio[1390]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41)
Mar 28 12:31:43 volumio volumio[1390]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7)
Mar 28 12:31:43 volumio volumio[1390]: at Object.onceWrapper (node:events:629:26)
Mar 28 12:31:43 volumio volumio[1390]: at ClientRequest.emit (node:events:514:28)
Mar 28 12:31:43 volumio volumio[1390]: at HTTPParser.parserOnIncomingClient [as onIncoming] (node:_http_client:693:27)
Mar 28 12:31:43 volumio volumio[1390]: at HTTPParser.parserOnHeadersComplete (node:_http_common:119:17)
Mar 28 12:31:43 volumio volumio[1390]: at TLSSocket.socketOnData (node:_http_client:535:22)
Mar 28 12:31:43 volumio volumio[1390]: at TLSSocket.emit (node:events:514:28)
Mar 28 12:31:43 volumio volumio[1390]: at addChunk (node:internal/streams/readable:343:12)
Mar 28 12:31:43 volumio volumio[1390]: at readableAddChunk (node:internal/streams/readable:316:9)
Mar 28 12:31:43 volumio volumio[1390]: at Readable.push (node:internal/streams/readable:253:10)
Mar 28 12:31:43 volumio volumio[1390]: at TLSWrap.onStreamRead (node:internal/stream_base_commons:190:23)
Mar 28 12:31:43 volumio volumio[1390]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 28 12:31:44 volumio sudo[2841]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-28 12:30'
Mar 28 12:31:44 volumio sudo[2841]: 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="dc61260dec5515dafd2b634881860b4c46c919ff"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026"
VOLUMIO_VERSION="4.103"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"