May 27 06:55:01 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:55:04 volumio volumio[9153]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:04 volumio volumio[9153]: info: Discovery: Restarting Browsing
May 27 06:55:04 volumio volumio[9153]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:04 volumio volumio[9153]: info: Discovery: Restarting Browsing
May 27 06:55:04 volumio volumio[9153]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:55:05 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:55:09 volumio volumio[9153]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:09 volumio volumio[9153]: info: Discovery: Restarting Browsing
May 27 06:55:09 volumio volumio[9153]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:09 volumio volumio[9153]: info: Discovery: Restarting Browsing
May 27 06:55:09 volumio volumio[9153]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:55:09 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: networkfs , addShare
May 27 06:55:09 volumio volumio[9153]: info: Adding a new share
May 27 06:55:09 volumio volumio[9153]: info: Share alias is blank
May 27 06:55:09 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:55:13 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
May 27 06:55:13 volumio volumio[9153]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12
May 27 06:55:13 volumio volumio[9153]: info: CoreCommandRouter::volumioGetState
May 27 06:55:13 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:55:14 volumio volumio[9153]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:14 volumio volumio[9153]: info: Discovery: Restarting Browsing
May 27 06:55:14 volumio volumio[9153]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:14 volumio volumio[9153]: info: Discovery: Restarting Browsing
May 27 06:55:14 volumio volumio[9153]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:55:17 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::volumioGetBrowseSources
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
May 27 06:55:18 volumio volumio[9153]: error: MyVolumio Plugin failed to authenticate in a timely fashion
May 27 06:55:18 volumio volumio[9153]: info: Completed starting MyVolumio Plugin
May 27 06:55:18 volumio volumio[9153]: [Metrics] CommandRouter: 37s 662.23ms
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::volumiosetStartupVolume
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::Close All Modals sent
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::Close All Modals sent
May 27 06:55:18 volumio volumio[9153]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav
May 27 06:55:18 volumio volumio[9153]: aplay: main:831: audio open error: Device or resource busy
May 27 06:55:18 volumio volumio-remote-updater[734]: Test mode disabled
May 27 06:55:18 volumio volumio-remote-updater[734]: Alpha mode disabled
May 27 06:55:18 volumio volumio-remote-updater[734]: Alpha legacy test mode disabled
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
May 27 06:55:18 volumio volumio[9153]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
May 27 06:55:18 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
May 27 06:55:19 volumio volumio[9153]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:19 volumio volumio[9153]: info: Discovery: Restarting Browsing
May 27 06:55:19 volumio volumio[9153]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:19 volumio volumio[9153]: info: Discovery: Restarting Browsing
May 27 06:55:19 volumio volumio[9153]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:55:19 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
May 27 06:55:19 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
May 27 06:55:19 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
May 27 06:55:21 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:55:22 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares
May 27 06:55:22 volumio volumio[9153]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService
May 27 06:55:22 volumio volumio[9153]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 27 06:55:22 volumio volumio[9153]: Error: getaddrinfo -3007
May 27 06:55:22 volumio volumio[9153]: at errnoException (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:199:11)
May 27 06:55:22 volumio volumio[9153]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:112:10)
May 27 06:55:22 volumio volumio[9153]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) {
May 27 06:55:22 volumio volumio[9153]: code: -3007,
May 27 06:55:22 volumio volumio[9153]: errno: -3007,
May 27 06:55:22 volumio volumio[9153]: syscall: 'getaddrinfo'
May 27 06:55:22 volumio volumio[9153]: }
May 27 06:55:22 volumio volumio[9153]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 27 06:55:22 volumio sudo[9567]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-27 06:54'
May 27 06:55:22 volumio sudo[9567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:23 volumio sudo[9567]: pam_unix(sudo:session): session closed for user root
May 27 06:55:23 volumio volumio-remote-updater[734]: [2026-05-27 06:55:23] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
May 27 06:55:23 volumio volumio-remote-updater[734]: [2026-05-27 06:55:23] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
May 27 06:55:23 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
May 27 06:55:23 volumio ntfs-3g[9231]: Unmounting /dev/sdb1 (ONtoch)
May 27 06:55:23 volumio volumio5-onboarding[2816]: time=2026-05-27T06:55:23.047+07:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF"
May 27 06:55:23 volumio systemd[1]: media-ONtoch.mount: Deactivated successfully.
May 27 06:55:23 volumio volumio5-onboarding[2816]: time=2026-05-27T06:55:23.053+07:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused"
May 27 06:55:23 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
May 27 06:55:23 volumio systemd[1]: volumio.service: Consumed 8.824s CPU time.
May 27 06:55:23 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
May 27 06:55:23 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
May 27 06:55:23 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 4.
May 27 06:55:23 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
May 27 06:55:23 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
May 27 06:55:23 volumio systemd[1]: volumio.service: Consumed 8.824s CPU time.
May 27 06:55:23 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
May 27 06:55:23 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
May 27 06:55:23 volumio volumio[9582]: info: -------------------------------------------
May 27 06:55:23 volumio volumio[9582]: info: ----- Volumio3 ----
May 27 06:55:23 volumio volumio[9582]: info: -------------------------------------------
May 27 06:55:23 volumio volumio[9582]: info: ----- System startup ----
May 27 06:55:23 volumio volumio[9582]: info: -------------------------------------------
May 27 06:55:24 volumio volumio[9582]: info: MYVOLUMIO Environment detected
May 27 06:55:24 volumio volumio[9582]: info: Plugin folders cleanup
May 27 06:55:24 volumio volumio[9582]: info: Scanning into folder /volumio/app/plugins/
May 27 06:55:24 volumio volumio[9582]: info: Scanning category audio_interface
May 27 06:55:24 volumio volumio[9582]: info: Scanning category miscellanea
May 27 06:55:24 volumio volumio[9582]: info: Scanning category music_service
May 27 06:55:24 volumio volumio[9582]: info: Scanning category plugins.json
May 27 06:55:24 volumio volumio[9582]: info: Scanning category system_controller
May 27 06:55:24 volumio volumio[9582]: info: Scanning category user_interface
May 27 06:55:24 volumio volumio[9582]: info: Scanning into folder /data/plugins/
May 27 06:55:24 volumio volumio[9582]: info: Plugin folders cleanup completed
May 27 06:55:24 volumio volumio[9582]: info: -------------------------------------------
May 27 06:55:24 volumio volumio[9582]: info: ----- Core plugins startup ----
May 27 06:55:24 volumio volumio[9582]: info: -------------------------------------------
May 27 06:55:24 volumio volumio[9582]: info: Loading plugins from folder /volumio/app/plugins/
May 27 06:55:24 volumio volumio[9582]: info: Adding plugin upnp to MyMusic Plugins
May 27 06:55:24 volumio volumio[9582]: info: Adding plugin airplay_emulation to MyMusic Plugins
May 27 06:55:24 volumio volumio[9582]: info: Adding plugin upnp_browser to MyMusic Plugins
May 27 06:55:24 volumio volumio[9582]: info: Loading plugins from folder /data/plugins/
May 27 06:55:24 volumio volumio[9582]: info: Loading plugin "system"...
May 27 06:55:24 volumio volumio[9582]: info: Loading plugin "appearance"...
May 27 06:55:24 volumio volumio[9582]: info: Loading plugin "network"...
May 27 06:55:24 volumio volumio[9582]: info: Refreshing Cached IP Addresses
May 27 06:55:24 volumio sudo[9613]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
May 27 06:55:24 volumio sudo[9613]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:24 volumio sudo[9611]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
May 27 06:55:24 volumio sudo[9611]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:24 volumio volumio[9582]: info: Loading plugin "services"...
May 27 06:55:24 volumio sudo[9620]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
May 27 06:55:24 volumio sudo[9620]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:24 volumio sudo[9613]: pam_unix(sudo:session): session closed for user root
May 27 06:55:24 volumio sudo[9611]: pam_unix(sudo:session): session closed for user root
May 27 06:55:24 volumio volumio[9582]: info: Loading plugin "volumio5onboarding"...
May 27 06:55:24 volumio sudo[9620]: pam_unix(sudo:session): session closed for user root
May 27 06:55:24 volumio volumio[9582]: info: Loading plugin "alsa_controller"...
May 27 06:55:24 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 27 06:55:24 volumio volumio[9582]: info: Loading plugin "wizard"...
May 27 06:55:24 volumio volumio[9582]: info: Loading plugin "networkfs"...
May 27 06:55:24 volumio volumio[9582]: info: Starting Udev Watcher for removable devices
May 27 06:55:24 volumio volumio[9582]: info: Mounting Device ONtoch
May 27 06:55:24 volumio sudo[9652]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sdb1 /mnt/USB/ONtoch -o noatime,dmask=0000,fmask=0000,iocharset=utf8
May 27 06:55:24 volumio sudo[9652]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:28 volumio volumio-remote-updater[734]: [2026-05-27 06:55:28] [connect] Successful connection
May 27 06:55:29 volumio ntfs-3g[9660]: Version 2022.10.3 integrated FUSE 28
May 27 06:55:29 volumio ntfs-3g[9660]: Mounted /dev/sdb1 (Read-Write, label "ONtoch", NTFS 3.1)
May 27 06:55:29 volumio ntfs-3g[9660]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8
May 27 06:55:29 volumio ntfs-3g[9660]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sdb1,blkdev,blksize=4096
May 27 06:55:29 volumio ntfs-3g[9660]: Global ownership and permissions enforced, configuration type 7
May 27 06:55:29 volumio sudo[9652]: pam_unix(sudo:session): session closed for user root
May 27 06:55:29 volumio volumio[9582]: info: Ignoring mount for partition: boot
May 27 06:55:29 volumio volumio[9582]: info: Ignoring mount for partition: volumio
May 27 06:55:29 volumio volumio[9582]: info: Ignoring mount for partition: volumio_data
May 27 06:55:29 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
May 27 06:55:29 volumio volumio[9582]: info: Loading plugin "volumio_command_line_client"...
May 27 06:55:29 volumio volumio[9582]: info: Loading plugin "upnp"...
May 27 06:55:29 volumio volumio[9582]: info: [1779839729893] Starting Upmpd Daemon
May 27 06:55:29 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
May 27 06:55:29 volumio volumio[9582]: info: Loading plugin "my_music"...
May 27 06:55:29 volumio volumio[9582]: info: Loading plugin "mpd"...
May 27 06:55:30 volumio volumio[9582]: info: Loading plugin "upnp_browser"...
May 27 06:55:30 volumio volumio[9582]: info: Starting UPNP Browser
May 27 06:55:30 volumio volumio[9582]: info: Loading plugin "alarm-clock"...
May 27 06:55:30 volumio volumio[9582]: info: Loading plugin "airplay_emulation"...
May 27 06:55:30 volumio volumio[9582]: info: Starting Shairport Sync
May 27 06:55:30 volumio volumio[9582]: info: Loading plugin "last_100"...
May 27 06:55:30 volumio volumio[9582]: info: Loading plugin "webradio"...
May 27 06:55:30 volumio volumio[9582]: info: Loading plugin "i2s_dacs"...
May 27 06:55:30 volumio volumio[9582]: info: I2S DAC not set, start Auto-detection
May 27 06:55:30 volumio volumio[9582]: info: Loading plugin "volumiodiscovery"...
May 27 06:55:30 volumio volumio[9582]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
May 27 06:55:30 volumio node[9582]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
May 27 06:55:30 volumio volumio[9582]: *** WARNING *** Please fix your application to use the native API of Avahi!
May 27 06:55:30 volumio node[9582]: *** WARNING *** Please fix your application to use the native API of Avahi!
May 27 06:55:30 volumio volumio[9582]: *** WARNING *** For more information see
May 27 06:55:30 volumio node[9582]: *** WARNING *** For more information see
May 27 06:55:30 volumio volumio[9582]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
May 27 06:55:30 volumio node[9582]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
May 27 06:55:30 volumio volumio[9582]: *** WARNING *** Please fix your application to use the native API of Avahi!
May 27 06:55:30 volumio node[9582]: *** WARNING *** Please fix your application to use the native API of Avahi!
May 27 06:55:30 volumio volumio[9582]: *** WARNING *** For more information see
May 27 06:55:30 volumio node[9582]: *** WARNING *** For more information see
May 27 06:55:30 volumio volumio[9582]: info: Applying required configuration parameters for plugin volumiodiscovery
May 27 06:55:32 volumio volumio[9582]: info: Discovery: Started advertising with name: Volumio
May 27 06:55:32 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
May 27 06:55:32 volumio volumio[9582]: info: Loading plugin "outputs"...
May 27 06:55:32 volumio volumio[9582]: info: Loading plugin "albumart"...
May 27 06:55:32 volumio volumio[9582]: info: Plugin example_plugin is not enabled
May 27 06:55:32 volumio volumio[9582]: info: Loading plugin "inputs"...
May 27 06:55:32 volumio volumio[9582]: info: Loading plugin "updater_comm"...
May 27 06:55:32 volumio volumio[9582]: info: Plugin mpdemulation is not enabled
May 27 06:55:32 volumio volumio[9582]: info: Loading plugin "rest_api"...
May 27 06:55:32 volumio volumio[9582]: info: Loading plugin "websocket"...
May 27 06:55:32 volumio volumio[9582]: info: Starting Socket.io Server version 1.7.4
May 27 06:55:32 volumio volumio[9582]: info: Loading i18n strings for locale ru
May 27 06:55:32 volumio volumio[9582]: Updating browse sources language
May 27 06:55:32 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 27 06:55:32 volumio volumio[9667]: Forking 1 albumart workers
May 27 06:55:32 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
May 27 06:55:32 volumio volumio[9582]: info: CoreCommandRouter::initPlayerControls
May 27 06:55:32 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:32 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:32 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:32 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:32 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:32 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:32 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:32 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:32 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
May 27 06:55:32 volumio volumio[9582]: Express server listening on port 3000
May 27 06:55:32 volumio volumio[9582]: [Metrics] WebUI: 8s 769.43ms
May 27 06:55:32 volumio volumio[9582]: info: Setting Device type: x86
May 27 06:55:32 volumio volumio[9582]: info: CoreStateMachine::resetVolumioState
May 27 06:55:32 volumio volumio[9582]: info: CoreStateMachine::getcurrentVolume
May 27 06:55:32 volumio volumio[9582]: info: CoreCommandRouter::volumioRetrievevolume
May 27 06:55:32 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:55:32 volumio volumio[9677]: Starting albumart workers
May 27 06:55:34 volumio volumio5-onboarding[2816]: time=2026-05-27T06:55:34.056+07:00 level=WARN msg="reconnection attempt failed" error="read tcp 127.0.0.1:34672->127.0.0.1:3000: i/o timeout"
May 27 06:55:35 volumio volumio[9582]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt'
May 27 06:55:35 volumio volumio[9582]: info: Completed loading Core Plugins
May 27 06:55:35 volumio volumio[9582]: info: Preparing to generate the ALSA configuration file
May 27 06:55:35 volumio volumio[9582]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf
May 27 06:55:35 volumio volumio[9582]: info: Reading ALSA contributions from plugins.
May 27 06:55:35 volumio volumio[9582]: info: Volumio Network Manager: Network status updated: 1
May 27 06:55:35 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:35 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:35 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 27 06:55:35 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:36 volumio volumio[9582]: info: CoreStateMachine::updateTrackBlock
May 27 06:55:36 volumio volumio[9582]: info: CorePlayQueue::getTrackBlock
May 27 06:55:36 volumio volumio[9582]: info: CoreCommandRouter::volumioRetrievevolume
May 27 06:55:36 volumio volumio[9582]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan
May 27 06:55:36 volumio volumio[9582]: wlan0 Interface doesn't support scanning.
May 27 06:55:36 volumio volumio[9582]: info: Cannot use regular scanning, forcing with ap-force
May 27 06:55:36 volumio sudo[9725]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force
May 27 06:55:36 volumio sudo[9725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:36 volumio sudo[9725]: pam_unix(sudo:session): session closed for user root
May 27 06:55:36 volumio volumio[9582]: command failed: No such device (-19)
May 27 06:55:36 volumio volumio[9582]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force
May 27 06:55:36 volumio volumio[9582]: command failed: No such device (-19)
May 27 06:55:36 volumio volumio[9582]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision
May 27 06:55:39 volumio volumio[9582]: verbose: New Socket.io Connection to 192.168.1.69 from 192.168.1.54 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/148.0.0.0 Safari/537.36 Edg/148.0.0.0 Engine version: 3 Transport: polling Total Clients: 1
May 27 06:55:39 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:39 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:39 volumio volumio[9582]: info: Reloading queue from file
May 27 06:55:39 volumio volumio[9582]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2
May 27 06:55:39 volumio volumio[9582]: info: CoreStateMachine::setRepeat null single undefined
May 27 06:55:39 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:39 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:39 volumio volumio[9582]: info: CoreStateMachine::setRandom null
May 27 06:55:39 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:39 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:39 volumio volumio[9582]: verbose: New Socket.io Connection to 192.168.1.69 from 192.168.1.54 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/148.0.0.0 Safari/537.36 Edg/148.0.0.0 Engine version: 3 Transport: polling Total Clients: 3
May 27 06:55:39 volumio volumio[9582]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4
May 27 06:55:39 volumio volumio[9582]: verbose: New Socket.io Connection to 192.168.1.69 from 192.168.1.54 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/148.0.0.0 Safari/537.36 Edg/148.0.0.0 Engine version: 3 Transport: polling Total Clients: 5
May 27 06:55:39 volumio volumio[9582]: info: Asound.conf file unchanged, so no further update is needed
May 27 06:55:39 volumio volumio[9582]: info: Output device has changed, restarting MPD
May 27 06:55:39 volumio volumio[9582]: info: Output device has changed, restarting Shairport Sync
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
May 27 06:55:39 volumio volumio[9582]: info: ___________ START PLUGINS ___________
May 27 06:55:39 volumio sudo[9739]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
May 27 06:55:39 volumio volumio[9582]: info: ControllerMpd::onStart: Initializing MPD
May 27 06:55:39 volumio volumio[9582]: info: Creating MPD Configuration file
May 27 06:55:39 volumio sudo[9739]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:39 volumio sudo[9741]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
May 27 06:55:39 volumio sudo[9741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:39 volumio sudo[9739]: pam_unix(sudo:session): session closed for user root
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 27 06:55:39 volumio volumio[9582]: info: [1779839739373] CoreMusicLibrary::Adding element Медиа-серверы
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 27 06:55:39 volumio sudo[9747]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service
May 27 06:55:39 volumio sudo[9747]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:39 volumio sudo[9749]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
May 27 06:55:39 volumio sudo[9749]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:39 volumio volumio[9582]: info: UPNP Browser: Client initialized successfully
May 27 06:55:39 volumio sudo[9749]: pam_unix(sudo:session): session closed for user root
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:55:39 volumio sudo[9754]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
May 27 06:55:39 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
May 27 06:55:39 volumio sudo[9754]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:39 volumio sudo[9747]: pam_unix(sudo:session): session closed for user root
May 27 06:55:39 volumio volumio[9582]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:55:39 volumio upmpdcli[1800]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0
May 27 06:55:39 volumio volumio[9582]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 27 06:55:39 volumio volumio[9582]: info: [1779839739430] CoreMusicLibrary::Adding element Last_100
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 27 06:55:39 volumio volumio[9582]: info: [1779839739431] CoreMusicLibrary::Adding element Webradio
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 27 06:55:39 volumio volumio[9582]: info: Initializing BBC Radios
May 27 06:55:39 volumio systemd[1]: mpd.service: Deactivated successfully.
May 27 06:55:39 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
May 27 06:55:39 volumio systemd[1]: mpd.service: Consumed 6.156s CPU time.
May 27 06:55:39 volumio systemd[1]: mpd.socket: Deactivated successfully.
May 27 06:55:39 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
May 27 06:55:39 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: Volumio Calling Home
May 27 06:55:39 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
May 27 06:55:39 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
May 27 06:55:39 volumio sudo[9779]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
May 27 06:55:39 volumio sudo[9779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
May 27 06:55:39 volumio sudo[9779]: pam_unix(sudo:session): session closed for user root
May 27 06:55:39 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:39 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:55:39 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:39 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:55:39 volumio volumio[9582]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:55:39 volumio volumio[9582]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6
May 27 06:55:39 volumio volumio[9582]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7
May 27 06:55:39 volumio volumio[9582]: info: MPD Permissions set
May 27 06:55:39 volumio volumio[9582]: info: MPD Permissions set
May 27 06:55:39 volumio volumio[9582]: verbose: New Socket.io Connection to 192.168.1.69 from 192.168.1.54 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/148.0.0.0 Safari/537.36 Edg/148.0.0.0 Engine version: 3 Transport: polling Total Clients: 7
May 27 06:55:39 volumio volumio[9582]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:55:39 volumio volumio[9582]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9
May 27 06:55:39 volumio volumio[9582]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 10
May 27 06:55:39 volumio volumio[9582]: info: Volumio called home
May 27 06:55:39 volumio volumio[9582]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 10
May 27 06:55:39 volumio volumio[9582]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 10
May 27 06:55:39 volumio volumio5-onboarding[2816]: time=2026-05-27T06:55:39.767+07:00 level=ERROR msg="failed reading message" error="websocket: RSV1 set, RSV3 set, bad opcode 11"
May 27 06:55:39 volumio volumio5-onboarding[2816]: panic: send on closed channel
May 27 06:55:39 volumio volumio5-onboarding[2816]: goroutine 758 [running]:
May 27 06:55:39 volumio volumio5-onboarding[2816]: github.com/VolumioTeam/volumio5-device-gateway/socketio.(*Client).readLoop(0xc0001e1ce0)
May 27 06:55:39 volumio volumio5-onboarding[2816]: /src/socketio/client.go:161 +0x216
May 27 06:55:39 volumio volumio5-onboarding[2816]: created by github.com/VolumioTeam/volumio5-device-gateway/socketio.(*Client).connect in goroutine 718
May 27 06:55:39 volumio volumio5-onboarding[2816]: /src/socketio/client.go:134 +0x605
May 27 06:55:39 volumio systemd[1]: volumio5-onboarding.service: Main process exited, code=exited, status=2/INVALIDARGUMENT
May 27 06:55:39 volumio systemd[1]: volumio5-onboarding.service: Failed with result 'exit-code'.
May 27 06:55:39 volumio volumio[9582]: info: Starting Shairport Sync
May 27 06:55:39 volumio volumio[9582]: info: Starting Shairport Sync
May 27 06:55:39 volumio sudo[9804]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
May 27 06:55:39 volumio sudo[9804]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:39 volumio volumio[9582]: info: Starting Shairport Sync
May 27 06:55:39 volumio sudo[9808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
May 27 06:55:39 volumio sudo[9808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
May 27 06:55:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
May 27 06:55:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
May 27 06:55:39 volumio systemd[1]: shairport-sync.service: Consumed 1.704s CPU time.
May 27 06:55:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
May 27 06:55:39 volumio sudo[9809]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
May 27 06:55:39 volumio sudo[9809]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:39 volumio sudo[9804]: pam_unix(sudo:session): session closed for user root
May 27 06:55:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
May 27 06:55:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
May 27 06:55:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
May 27 06:55:39 volumio systemd[1]: volumio5-onboarding.service: Scheduled restart job, restart counter is at 16.
May 27 06:55:39 volumio volumio[9582]: info: Shairport-Sync Started
May 27 06:55:39 volumio volumio[9582]: Error adding Membership: Error: addMembership EINVAL
May 27 06:55:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
May 27 06:55:39 volumio systemd[1]: Stopped volumio5-onboarding.service - Volumio5 Onboarding Server.
May 27 06:55:39 volumio systemd[1]: Started volumio5-onboarding.service - Volumio5 Onboarding Server.
May 27 06:55:39 volumio sudo[9808]: pam_unix(sudo:session): session closed for user root
May 27 06:55:39 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
May 27 06:55:39 volumio volumio[9582]: info: CoreCommandRouter::volumioGetState
May 27 06:55:39 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:39 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
May 27 06:55:39 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
May 27 06:55:39 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
May 27 06:55:39 volumio sudo[9816]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
May 27 06:55:39 volumio sudo[9816]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:39 volumio sudo[9809]: pam_unix(sudo:session): session closed for user root
May 27 06:55:39 volumio sudo[9816]: pam_unix(sudo:session): session closed for user root
May 27 06:55:39 volumio sudo[9819]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
May 27 06:55:39 volumio sudo[9819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:39 volumio sudo[9819]: pam_unix(sudo:session): session closed for user root
May 27 06:55:40 volumio volumio[9582]: info: Shairport-Sync Started
May 27 06:55:40 volumio volumio[9582]: info: Shairport-Sync Started
May 27 06:55:40 volumio sudo[9839]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
May 27 06:55:40 volumio sudo[9839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:40 volumio sudo[9839]: pam_unix(sudo:session): session closed for user root
May 27 06:55:40 volumio volumio[9582]: info: Upmpdcli Daemon Started
May 27 06:55:40 volumio volumio-remote-updater[734]: [2026-05-27 06:55:40] [connect] Successful connection
May 27 06:55:41 volumio volumio-remote-updater[734]: [2026-05-27 06:55:41] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1779839740 101
May 27 06:55:41 volumio volumio[9582]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 10
May 27 06:55:41 volumio mpd[9784]: 2026-05-27T06:55:41 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
May 27 06:55:41 volumio systemd[1]: Started mpd.service - Music Player Daemon.
May 27 06:55:41 volumio upmpdcli[1800]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started
May 27 06:55:41 volumio sudo[9754]: pam_unix(sudo:session): session closed for user root
May 27 06:55:41 volumio sudo[9741]: pam_unix(sudo:session): session closed for user root
May 27 06:55:41 volumio volumio[9582]: info: Completed starting Core Plugins
May 27 06:55:41 volumio volumio[9582]: info: -------------------------------------------
May 27 06:55:41 volumio volumio[9582]: info: ----- MyVolumio plugins startup ----
May 27 06:55:41 volumio volumio[9582]: info: -------------------------------------------
May 27 06:55:41 volumio volumio[9582]: info: [MyVolumio PluginManager] Fetching plans data....
May 27 06:55:41 volumio volumio[9582]: error: MPD error: The expression evaluated to a falsy value:
May 27 06:55:41 volumio volumio[9582]: assert.ok(self.idling)
May 27 06:55:41 volumio volumio[9582]: error: The expression evaluated to a falsy value:
May 27 06:55:41 volumio volumio[9582]: assert.ok(self.idling)
May 27 06:55:41 volumio volumio[9582]: info: MPD running with PID9784
May 27 06:55:41 volumio volumio[9582]: ,establishing connection
May 27 06:55:41 volumio volumio[9582]: error: updateQueue error: null
May 27 06:55:41 volumio volumio[9582]: error: updateQueue error: null
May 27 06:55:42 volumio volumio[9582]: verbose: New Socket.io Connection to 192.168.1.69 from 192.168.1.54 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/148.0.0.0 Safari/537.36 Edg/148.0.0.0 Engine version: 3 Transport: polling Total Clients: 11
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::volumioGetVisibleSources
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::volumioGetState
May 27 06:55:42 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::volumioGetQueue
May 27 06:55:42 volumio volumio[9582]: info: CoreStateMachine::getQueue
May 27 06:55:42 volumio volumio[9582]: info: CorePlayQueue::getQueue
May 27 06:55:42 volumio volumio[9582]: info: Listing playlists
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
May 27 06:55:42 volumio volumio5-onboarding[9814]: time=2026-05-27T06:55:42.484+07:00 level=INFO msg="running volumio5-device-gateway" version=6370e0a8+CHANGES buildDate=2026-03-06T16:29:42Z
May 27 06:55:42 volumio volumio[9582]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 12
May 27 06:55:42 volumio volumio[9582]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 12
May 27 06:55:42 volumio volumio5-onboarding[9814]: time=2026-05-27T06:55:42.543+07:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci0 error="bluetooth: adapter /org/bluez/hci0 does not exist"
May 27 06:55:42 volumio volumio5-onboarding[9814]: time=2026-05-27T06:55:42.543+07:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci1 error="bluetooth: adapter /org/bluez/hci1 does not exist"
May 27 06:55:42 volumio volumio5-onboarding[9814]: time=2026-05-27T06:55:42.544+07:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci2 error="bluetooth: adapter /org/bluez/hci2 does not exist"
May 27 06:55:42 volumio volumio5-onboarding[9814]: time=2026-05-27T06:55:42.545+07:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci3 error="bluetooth: adapter /org/bluez/hci3 does not exist"
May 27 06:55:42 volumio volumio5-onboarding[9814]: time=2026-05-27T06:55:42.545+07:00 level=WARN msg="failed to enable Bluetooth adapter" adapter=hci4 error="bluetooth: adapter /org/bluez/hci4 does not exist"
May 27 06:55:42 volumio volumio5-onboarding[9814]: time=2026-05-27T06:55:42.545+07:00 level=WARN msg="no Bluetooth adapter found, BLE discovery disabled"
May 27 06:55:42 volumio volumio[9582]: info: Received Get System Info
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 27 06:55:42 volumio volumio[9582]: info: Discovery: Getting this device information
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::volumioGetState
May 27 06:55:42 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 27 06:55:42 volumio volumio5-onboarding[9814]: time=2026-05-27T06:55:42.550+07:00 level=INFO msg="system info for 4b562a1d4062069eacd3427e305a21fd" deviceName=Volumio deviceVariant=volumio deviceModel= softwareVersion=4.119
May 27 06:55:42 volumio volumio5-onboarding[9814]: time=2026-05-27T06:55:42.595+07:00 level=INFO msg="bootstrapping state" hasInternet=true
May 27 06:55:42 volumio volumio[9582]: info: Received Get System Info
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 27 06:55:42 volumio volumio[9582]: info: Discovery: Getting this device information
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::volumioGetState
May 27 06:55:42 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 27 06:55:42 volumio volumio-remote-updater[734]: Test mode disabled
May 27 06:55:42 volumio volumio-remote-updater[734]: Alpha mode disabled
May 27 06:55:42 volumio volumio-remote-updater[734]: Alpha legacy test mode disabled
May 27 06:55:42 volumio volumio[9582]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
May 27 06:55:42 volumio volumio5-onboarding[9814]: time=2026-05-27T06:55:42.817+07:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=tidal error="could not open plugin config file for \"tidal\": open /data/configuration/music_service/tidal/config.json: no such file or directory"
May 27 06:55:42 volumio volumio5-onboarding[9814]: time=2026-05-27T06:55:42.817+07:00 level=WARN msg="could not read OAuth data for music provider" component=volumio provider=qobuz error="could not open plugin config file for \"qobuz\": open /data/configuration/music_service/qobuz/config.json: no such file or directory"
May 27 06:55:42 volumio volumio5-onboarding[9814]: time=2026-05-27T06:55:42.818+07:00 level=WARN msg="could not read username/password data for music provider" component=volumio provider=hi_res_audio error="could not open plugin config file for \"hi_res_audio\": open /data/configuration/music_service/hi_res_audio/config.json: no such file or directory"
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
May 27 06:55:42 volumio volumio[9582]: info: Received Get System Info
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 27 06:55:42 volumio volumio[9582]: info: Discovery: Getting this device information
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::volumioGetState
May 27 06:55:42 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
May 27 06:55:42 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
May 27 06:55:42 volumio volumio5-onboarding[9814]: time=2026-05-27T06:55:42.825+07:00 level=INFO msg="enabling local network discovery"
May 27 06:55:42 volumio volumio[9582]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 13
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::volumioGetVisibleSources
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::volumioGetState
May 27 06:55:43 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::volumioPlay
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::play index undefined
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::setConsumeUpdateService undefined
May 27 06:55:43 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::startPlaybackTimer
May 27 06:55:43 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:43 volumio volumio[9582]: info: [1779839743491] ControllerWebradio::clearAddPlayTrack
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand stop
May 27 06:55:43 volumio volumio[9582]: info: sendMpdCommand stop took 1 milliseconds
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand clear
May 27 06:55:43 volumio volumio[9582]: info: sendMpdCommand clear took 1 milliseconds
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand load "http://stream.funradio.sk:8000/80-90-128.mp3"
May 27 06:55:43 volumio volumio[9582]: info:
May 27 06:55:43 volumio volumio[9582]: ---------------------------- MPD announces system playlist update
May 27 06:55:43 volumio volumio[9582]: info: Ignoring MPD Status Update
May 27 06:55:43 volumio volumio[9582]: info:
May 27 06:55:43 volumio volumio[9582]: ---------------------------- MPD announces system playlist update
May 27 06:55:43 volumio volumio[9582]: info: Ignoring MPD Status Update
May 27 06:55:43 volumio volumio[9582]: info:
May 27 06:55:43 volumio volumio[9582]: ---------------------------- MPD announces system playlist update
May 27 06:55:43 volumio volumio[9582]: info: Ignoring MPD Status Update
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand add "http://stream.funradio.sk:8000/80-90-128.mp3"
May 27 06:55:43 volumio volumio[9582]: error: updateQueue error: null
May 27 06:55:43 volumio volumio[9582]: error: updateQueue error: null
May 27 06:55:43 volumio volumio[9582]: error: updateQueue error: null
May 27 06:55:43 volumio volumio[9582]: info: ------------------------------ 241ms
May 27 06:55:43 volumio volumio[9582]: info: ------------------------------ 240ms
May 27 06:55:43 volumio volumio[9582]: info: ------------------------------ 239ms
May 27 06:55:43 volumio volumio[9582]: info:
May 27 06:55:43 volumio volumio[9582]: ---------------------------- MPD announces system playlist update
May 27 06:55:43 volumio volumio[9582]: info: Ignoring MPD Status Update
May 27 06:55:43 volumio volumio[9582]: info: sendMpdCommand add "http://stream.funradio.sk:8000/80-90-128.mp3" took 2 milliseconds
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::setConsumeUpdateService mpd
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand play
May 27 06:55:43 volumio volumio[9582]: info:
May 27 06:55:43 volumio volumio[9582]: ---------------------------- MPD announces system playlist update
May 27 06:55:43 volumio volumio[9582]: info: Ignoring MPD Status Update
May 27 06:55:43 volumio volumio[9582]: info:
May 27 06:55:43 volumio volumio[9582]: ---------------------------- MPD announces system playlist update
May 27 06:55:43 volumio volumio[9582]: info: Ignoring MPD Status Update
May 27 06:55:43 volumio volumio[9582]: info: ------------------------------ 3ms
May 27 06:55:43 volumio volumio[9582]: info: sendMpdCommand play took 3 milliseconds
May 27 06:55:43 volumio volumio[9582]: info: ------------------------------ 2ms
May 27 06:55:43 volumio volumio[9582]: info: ------------------------------ 2ms
May 27 06:55:43 volumio volumio5-onboarding[9814]: time=2026-05-27T06:55:43.766+07:00 level=INFO msg="service successfully established" component=discovery/localnet
May 27 06:55:43 volumio volumio[9582]: info:
May 27 06:55:43 volumio volumio[9582]: ---------------------------- MPD announces state update: player
May 27 06:55:43 volumio volumio[9582]: info: ControllerMpd::getState
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:55:43 volumio volumio[9582]: info:
May 27 06:55:43 volumio volumio[9582]: ---------------------------- MPD announces state update: player
May 27 06:55:43 volumio volumio[9582]: info: ControllerMpd::getState
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:55:43 volumio volumio[9582]: info:
May 27 06:55:43 volumio volumio[9582]: ---------------------------- MPD announces state update: player
May 27 06:55:43 volumio volumio[9582]: info: ControllerMpd::getState
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:55:43 volumio volumio[9582]: info:
May 27 06:55:43 volumio volumio[9582]: ---------------------------- MPD announces state update: player
May 27 06:55:43 volumio volumio[9582]: info: sendMpdCommand status took 11 milliseconds
May 27 06:55:43 volumio volumio[9582]: info: sendMpdCommand status took 11 milliseconds
May 27 06:55:43 volumio volumio[9582]: info: sendMpdCommand status took 10 milliseconds
May 27 06:55:43 volumio volumio[9582]: info: ControllerMpd::getState
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::parseState
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::parseState
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::parseState
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:55:43 volumio volumio[9582]: info:
May 27 06:55:43 volumio volumio[9582]: ---------------------------- MPD announces state update: player
May 27 06:55:43 volumio volumio[9582]: info: ControllerMpd::getState
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:55:43 volumio volumio[9582]: info:
May 27 06:55:43 volumio volumio[9582]: ---------------------------- MPD announces state update: player
May 27 06:55:43 volumio volumio[9582]: info: ControllerMpd::getState
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:55:43 volumio volumio[9582]: info: sendMpdCommand status took 4 milliseconds
May 27 06:55:43 volumio volumio[9582]: info: sendMpdCommand playlistinfo took 3 milliseconds
May 27 06:55:43 volumio volumio[9582]: info: sendMpdCommand playlistinfo took 2 milliseconds
May 27 06:55:43 volumio volumio[9582]: info: sendMpdCommand playlistinfo took 3 milliseconds
May 27 06:55:43 volumio volumio[9582]: info: sendMpdCommand status took 2 milliseconds
May 27 06:55:43 volumio volumio[9582]: info: sendMpdCommand status took 2 milliseconds
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::parseState
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::parseTrackInfo
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::parseTrackInfo
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::parseTrackInfo
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::parseState
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::parseState
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:55:43 volumio volumio[9582]: info: ControllerMpd::pushState
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::servicePushState
May 27 06:55:43 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:43 volumio volumio[9582]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"80-90-128.mp3","artist":null,"album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:55:43 volumio volumio[9582]: verbose: CURRENT POSITION 0
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::syncState stateService play
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::syncState currentStatus stop
May 27 06:55:43 volumio volumio[9582]: info: ControllerMpd::pushState
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::servicePushState
May 27 06:55:43 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:43 volumio volumio[9582]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"80-90-128.mp3","artist":null,"album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:55:43 volumio volumio[9582]: verbose: CURRENT POSITION 0
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::syncState stateService play
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::syncState currentStatus play
May 27 06:55:43 volumio volumio[9582]: info: Received an update from plugin. extracting info from payload
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:43 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:43 volumio volumio[9582]: info: ControllerMpd::pushState
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::servicePushState
May 27 06:55:43 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:43 volumio volumio[9582]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"80-90-128.mp3","artist":null,"album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:55:43 volumio volumio[9582]: verbose: CURRENT POSITION 0
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::syncState stateService play
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::syncState currentStatus play
May 27 06:55:43 volumio volumio[9582]: info: Received an update from plugin. extracting info from payload
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:43 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:43 volumio volumio[9582]: info: ------------------------------ 28ms
May 27 06:55:43 volumio volumio[9582]: info: ------------------------------ 37ms
May 27 06:55:43 volumio volumio[9582]: info: ------------------------------ 39ms
May 27 06:55:43 volumio volumio[9582]: info: sendMpdCommand playlistinfo took 24 milliseconds
May 27 06:55:43 volumio volumio[9582]: info: sendMpdCommand playlistinfo took 24 milliseconds
May 27 06:55:43 volumio volumio[9582]: info: sendMpdCommand playlistinfo took 23 milliseconds
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::parseTrackInfo
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::parseTrackInfo
May 27 06:55:43 volumio volumio[9582]: verbose: ControllerMpd::parseTrackInfo
May 27 06:55:43 volumio volumio[9582]: info: ControllerMpd::pushState
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::servicePushState
May 27 06:55:43 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:43 volumio volumio[9582]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"80-90-128.mp3","artist":null,"album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:55:43 volumio volumio[9582]: verbose: CURRENT POSITION 0
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::syncState stateService play
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::syncState currentStatus play
May 27 06:55:43 volumio volumio[9582]: info: Received an update from plugin. extracting info from payload
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:43 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:43 volumio volumio[9582]: info: ControllerMpd::pushState
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::servicePushState
May 27 06:55:43 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:43 volumio volumio[9582]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"80-90-128.mp3","artist":null,"album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:55:43 volumio volumio[9582]: verbose: CURRENT POSITION 0
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::syncState stateService play
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::syncState currentStatus play
May 27 06:55:43 volumio volumio[9582]: info: Received an update from plugin. extracting info from payload
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:43 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:43 volumio volumio[9582]: info: ControllerMpd::pushState
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::servicePushState
May 27 06:55:43 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:43 volumio volumio[9582]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"80-90-128.mp3","artist":null,"album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:55:43 volumio volumio[9582]: verbose: CURRENT POSITION 0
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::syncState stateService play
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::syncState currentStatus play
May 27 06:55:43 volumio volumio[9582]: info: Received an update from plugin. extracting info from payload
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:43 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:43 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:43 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:43 volumio volumio[9582]: info: ------------------------------ 60ms
May 27 06:55:43 volumio volumio[9582]: info: ------------------------------ 57ms
May 27 06:55:43 volumio volumio[9582]: info: ------------------------------ 57ms
May 27 06:55:44 volumio volumio[9582]: info:
May 27 06:55:44 volumio volumio[9582]: ---------------------------- MPD announces system playlist update
May 27 06:55:44 volumio volumio[9582]: info: Ignoring MPD Status Update
May 27 06:55:44 volumio volumio[9582]: info:
May 27 06:55:44 volumio volumio[9582]: ---------------------------- MPD announces state update: player
May 27 06:55:44 volumio volumio[9582]: info: ControllerMpd::getState
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:55:44 volumio volumio[9582]: info:
May 27 06:55:44 volumio volumio[9582]: ---------------------------- MPD announces system playlist update
May 27 06:55:44 volumio volumio[9582]: info: Ignoring MPD Status Update
May 27 06:55:44 volumio volumio[9582]: info:
May 27 06:55:44 volumio volumio[9582]: ---------------------------- MPD announces state update: player
May 27 06:55:44 volumio volumio[9582]: info: ControllerMpd::getState
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:55:44 volumio volumio[9582]: info:
May 27 06:55:44 volumio volumio[9582]: ---------------------------- MPD announces system playlist update
May 27 06:55:44 volumio volumio[9582]: info: Ignoring MPD Status Update
May 27 06:55:44 volumio volumio[9582]: info:
May 27 06:55:44 volumio volumio[9582]: ---------------------------- MPD announces state update: player
May 27 06:55:44 volumio volumio[9582]: info:
May 27 06:55:44 volumio volumio[9582]: ---------------------------- MPD announces system playlist update
May 27 06:55:44 volumio volumio[9582]: info: Ignoring MPD Status Update
May 27 06:55:44 volumio volumio[9582]: info:
May 27 06:55:44 volumio volumio[9582]: ---------------------------- MPD announces state update: player
May 27 06:55:44 volumio volumio[9582]: info: ControllerMpd::getState
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:55:44 volumio volumio[9582]: info: ------------------------------ 23ms
May 27 06:55:44 volumio volumio[9582]: info: ControllerMpd::getState
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:55:44 volumio volumio[9582]: info: sendMpdCommand status took 17 milliseconds
May 27 06:55:44 volumio volumio[9582]: info: ------------------------------ 16ms
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::parseState
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:55:44 volumio volumio[9582]: info:
May 27 06:55:44 volumio volumio[9582]: ---------------------------- MPD announces system playlist update
May 27 06:55:44 volumio volumio[9582]: info: Ignoring MPD Status Update
May 27 06:55:44 volumio volumio[9582]: info:
May 27 06:55:44 volumio volumio[9582]: ---------------------------- MPD announces state update: player
May 27 06:55:44 volumio volumio[9582]: info: ControllerMpd::getState
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:55:44 volumio volumio[9582]: info:
May 27 06:55:44 volumio volumio[9582]: ---------------------------- MPD announces system playlist update
May 27 06:55:44 volumio volumio[9582]: info: Ignoring MPD Status Update
May 27 06:55:44 volumio volumio[9582]: info:
May 27 06:55:44 volumio volumio[9582]: ---------------------------- MPD announces state update: player
May 27 06:55:44 volumio volumio[9582]: info: ControllerMpd::getState
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:55:44 volumio volumio[9582]: info: sendMpdCommand status took 24 milliseconds
May 27 06:55:44 volumio volumio[9582]: info: ------------------------------ 24ms
May 27 06:55:44 volumio volumio[9582]: info: sendMpdCommand status took 10 milliseconds
May 27 06:55:44 volumio volumio[9582]: info: ------------------------------ 17ms
May 27 06:55:44 volumio volumio[9582]: info: sendMpdCommand status took 10 milliseconds
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::parseState
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::parseState
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::parseState
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:55:44 volumio volumio[9582]: info: sendMpdCommand playlistinfo took 13 milliseconds
May 27 06:55:44 volumio volumio[9582]: info: ------------------------------ 22ms
May 27 06:55:44 volumio volumio[9582]: info: sendMpdCommand status took 28 milliseconds
May 27 06:55:44 volumio volumio[9582]: info: ------------------------------ 34ms
May 27 06:55:44 volumio volumio[9582]: info: sendMpdCommand status took 34 milliseconds
May 27 06:55:44 volumio volumio[9582]: info: sendMpdCommand playlistinfo took 31 milliseconds
May 27 06:55:44 volumio volumio[9582]: info: sendMpdCommand playlistinfo took 31 milliseconds
May 27 06:55:44 volumio volumio[9582]: info: sendMpdCommand playlistinfo took 30 milliseconds
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::parseTrackInfo
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::parseState
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::parseState
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::parseTrackInfo
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::parseTrackInfo
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::parseTrackInfo
May 27 06:55:44 volumio volumio[9582]: info: ControllerMpd::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::servicePushState
May 27 06:55:44 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:44 volumio volumio[9582]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Depeche Mode - I Feel You","artist":"FUN Radio 80-90","album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:55:44 volumio volumio[9582]: verbose: CURRENT POSITION 0
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::syncState stateService play
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::syncState currentStatus play
May 27 06:55:44 volumio volumio[9582]: info: Received an update from plugin. extracting info from payload
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:44 volumio volumio[9582]: info: ControllerMpd::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::servicePushState
May 27 06:55:44 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:44 volumio volumio[9582]: verbose: STATE SERVICE {"status":"play","position":0,"seek":250,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Depeche Mode - I Feel You","artist":"FUN Radio 80-90","album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:55:44 volumio volumio[9582]: verbose: CURRENT POSITION 0
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::syncState stateService play
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::syncState currentStatus play
May 27 06:55:44 volumio volumio[9582]: info: Received an update from plugin. extracting info from payload
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:44 volumio volumio[9582]: info: ControllerMpd::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::servicePushState
May 27 06:55:44 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:44 volumio volumio[9582]: verbose: STATE SERVICE {"status":"play","position":0,"seek":387,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Depeche Mode - I Feel You","artist":"FUN Radio 80-90","album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:55:44 volumio volumio[9582]: verbose: CURRENT POSITION 0
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::syncState stateService play
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::syncState currentStatus play
May 27 06:55:44 volumio volumio[9582]: info: Received an update from plugin. extracting info from payload
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:44 volumio volumio[9582]: info: ControllerMpd::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::servicePushState
May 27 06:55:44 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:44 volumio volumio[9582]: verbose: STATE SERVICE {"status":"play","position":0,"seek":387,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Depeche Mode - I Feel You","artist":"FUN Radio 80-90","album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:55:44 volumio volumio[9582]: verbose: CURRENT POSITION 0
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::syncState stateService play
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::syncState currentStatus play
May 27 06:55:44 volumio volumio[9582]: info: Received an update from plugin. extracting info from payload
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:44 volumio volumio[9582]: info: ------------------------------ 129ms
May 27 06:55:44 volumio volumio[9582]: info: ------------------------------ 131ms
May 27 06:55:44 volumio volumio[9582]: info: ------------------------------ 123ms
May 27 06:55:44 volumio volumio[9582]: info: ------------------------------ 117ms
May 27 06:55:44 volumio volumio[9582]: info: sendMpdCommand playlistinfo took 80 milliseconds
May 27 06:55:44 volumio volumio[9582]: info: sendMpdCommand playlistinfo took 80 milliseconds
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::parseTrackInfo
May 27 06:55:44 volumio volumio[9582]: verbose: ControllerMpd::parseTrackInfo
May 27 06:55:44 volumio volumio[9582]: info: ControllerMpd::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::servicePushState
May 27 06:55:44 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:44 volumio volumio[9582]: verbose: STATE SERVICE {"status":"play","position":0,"seek":524,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Depeche Mode - I Feel You","artist":"FUN Radio 80-90","album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:55:44 volumio volumio[9582]: verbose: CURRENT POSITION 0
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::syncState stateService play
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::syncState currentStatus play
May 27 06:55:44 volumio volumio[9582]: info: Received an update from plugin. extracting info from payload
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:44 volumio volumio[9582]: info: ControllerMpd::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::servicePushState
May 27 06:55:44 volumio volumio[9582]: info: CorePlayQueue::getTrack 0
May 27 06:55:44 volumio volumio[9582]: verbose: STATE SERVICE {"status":"play","position":0,"seek":524,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Depeche Mode - I Feel You","artist":"FUN Radio 80-90","album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:55:44 volumio volumio[9582]: verbose: CURRENT POSITION 0
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::syncState stateService play
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::syncState currentStatus play
May 27 06:55:44 volumio volumio[9582]: info: Received an update from plugin. extracting info from payload
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:44 volumio volumio[9582]: info: CoreStateMachine::pushState
May 27 06:55:44 volumio volumio[9582]: info: CoreCommandRouter::volumioPushState
May 27 06:55:44 volumio volumio[9582]: info: ------------------------------ 222ms
May 27 06:55:44 volumio volumio[9582]: info: ------------------------------ 222ms
May 27 06:55:44 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:44 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:55:44 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:44 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:55:44 volumio volumio[9582]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:55:45 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:55:49 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:49 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:55:49 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:49 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:55:49 volumio volumio[9582]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:55:49 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
May 27 06:55:50 volumio volumio[9582]: info: Adding plugin bluetooth to MyMusic Plugins
May 27 06:55:50 volumio volumio[9582]: info: Adding plugin multiroom to MyMusic Plugins
May 27 06:55:50 volumio volumio[9582]: info: Adding plugin metavolumio to MyMusic Plugins
May 27 06:55:50 volumio volumio[9582]: info: Adding plugin cd_controller to MyMusic Plugins
May 27 06:55:50 volumio volumio[9582]: info: Adding plugin qobuzconnect to MyMusic Plugins
May 27 06:55:50 volumio volumio[9582]: info: Adding plugin smart_inputs to MyMusic Plugins
May 27 06:55:50 volumio volumio[9582]: info: Adding plugin tidalconnect to MyMusic Plugins
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
May 27 06:55:50 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:55:50 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:55:50 volumio volumio[9582]: info: Starting MyVolumio Remote Streaming Endpoints
May 27 06:55:50 volumio volumio[9582]: info: MyVolumio not started
May 27 06:55:50 volumio volumio[9582]: info: Initializing device activation check
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
May 27 06:55:50 volumio volumio[9582]: info: Streaming services startup
May 27 06:55:50 volumio volumio[9582]: info: Starting Streaming Daemon
May 27 06:55:50 volumio volumio[9582]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
May 27 06:55:50 volumio sudo[9906]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
May 27 06:55:50 volumio sudo[9906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:55:50 volumio sudo[9906]: pam_unix(sudo:session): session closed for user root
May 27 06:55:50 volumio volumio[9582]: error: Cannot start Volumio Streaming Daemon
May 27 06:55:50 volumio volumio[9582]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
May 27 06:55:50 volumio volumio[9582]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
May 27 06:55:53 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:55:54 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:54 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:55:54 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:54 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:55:54 volumio volumio[9582]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:55:57 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:55:59 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:59 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:55:59 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:55:59 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:55:59 volumio volumio[9582]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:56:01 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:56:04 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:04 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:56:04 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:04 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:56:04 volumio volumio[9582]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:56:05 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
May 27 06:56:05 volumio volumio[9582]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14
May 27 06:56:05 volumio volumio[9582]: info: CoreCommandRouter::volumioGetState
May 27 06:56:05 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:56:09 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 27 06:56:09 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:56:09 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
May 27 06:56:09 volumio volumio-remote-updater[734]: Test mode disabled
May 27 06:56:09 volumio volumio-remote-updater[734]: Alpha mode disabled
May 27 06:56:09 volumio volumio-remote-updater[734]: Alpha legacy test mode disabled
May 27 06:56:09 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
May 27 06:56:09 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:09 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:56:09 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:09 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:56:09 volumio volumio[9582]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:56:09 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:56:09 volumio volumio[9582]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
May 27 06:56:09 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
May 27 06:56:10 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:10 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:10 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
May 27 06:56:10 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
May 27 06:56:10 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
May 27 06:56:10 volumio volumio[9582]: info: CoreCommandRouter::volumioGetBrowseSources
May 27 06:56:10 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 27 06:56:10 volumio volumio[9582]: error: MyVolumio Plugin failed to authenticate in a timely fashion
May 27 06:56:10 volumio volumio[9582]: info: Completed starting MyVolumio Plugin
May 27 06:56:10 volumio volumio[9582]: [Metrics] CommandRouter: 47s 69.75ms
May 27 06:56:10 volumio volumio[9582]: info: CoreCommandRouter::volumiosetStartupVolume
May 27 06:56:10 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:10 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:56:10 volumio volumio[9582]: info: CoreCommandRouter::Close All Modals sent
May 27 06:56:10 volumio volumio[9582]: info: CoreCommandRouter::Close All Modals sent
May 27 06:56:10 volumio volumio[9582]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav
May 27 06:56:10 volumio volumio[9582]: aplay: main:831: audio open error: Device or resource busy
May 27 06:56:11 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
May 27 06:56:11 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
May 27 06:56:11 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
May 27 06:56:13 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:56:14 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:14 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:56:14 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:14 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:56:14 volumio volumio[9582]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:56:17 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:56:17 volumio volumio[9582]: info: BOOT COMPLETED
May 27 06:56:19 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:19 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:56:19 volumio volumio[9582]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:19 volumio volumio[9582]: info: Discovery: Restarting Browsing
May 27 06:56:19 volumio volumio[9582]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:56:21 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:56:22 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: networkfs , addShare
May 27 06:56:22 volumio volumio[9582]: info: Adding a new share
May 27 06:56:24 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares
May 27 06:56:24 volumio volumio[9582]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService
May 27 06:56:24 volumio volumio[9582]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 27 06:56:24 volumio volumio[9582]: Error: getaddrinfo -3007
May 27 06:56:24 volumio volumio[9582]: at errnoException (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:199:11)
May 27 06:56:24 volumio volumio[9582]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:112:10)
May 27 06:56:24 volumio volumio[9582]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) {
May 27 06:56:24 volumio volumio[9582]: code: -3007,
May 27 06:56:24 volumio volumio[9582]: errno: -3007,
May 27 06:56:24 volumio volumio[9582]: syscall: 'getaddrinfo'
May 27 06:56:24 volumio volumio[9582]: }
May 27 06:56:24 volumio volumio[9582]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 27 06:56:24 volumio sudo[10048]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-27 06:55'
May 27 06:56:24 volumio sudo[10048]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:25 volumio sudo[10048]: pam_unix(sudo:session): session closed for user root
May 27 06:56:25 volumio volumio5-onboarding[9814]: time=2026-05-27T06:56:25.071+07:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF"
May 27 06:56:25 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
May 27 06:56:25 volumio volumio-remote-updater[734]: [2026-05-27 06:56:25] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
May 27 06:56:25 volumio volumio-remote-updater[734]: [2026-05-27 06:56:25] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
May 27 06:56:25 volumio volumio5-onboarding[9814]: time=2026-05-27T06:56:25.073+07:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused"
May 27 06:56:25 volumio systemd[1]: media-ONtoch.mount: Deactivated successfully.
May 27 06:56:25 volumio ntfs-3g[9660]: Unmounting /dev/sdb1 (ONtoch)
May 27 06:56:25 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
May 27 06:56:25 volumio systemd[1]: volumio.service: Consumed 9.125s CPU time.
May 27 06:56:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
May 27 06:56:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
May 27 06:56:25 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 5.
May 27 06:56:25 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
May 27 06:56:25 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
May 27 06:56:25 volumio systemd[1]: volumio.service: Consumed 9.125s CPU time.
May 27 06:56:25 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
May 27 06:56:25 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
May 27 06:56:25 volumio volumio[10063]: info: -------------------------------------------
May 27 06:56:25 volumio volumio[10063]: info: ----- Volumio3 ----
May 27 06:56:25 volumio volumio[10063]: info: -------------------------------------------
May 27 06:56:25 volumio volumio[10063]: info: ----- System startup ----
May 27 06:56:25 volumio volumio[10063]: info: -------------------------------------------
May 27 06:56:26 volumio volumio[10063]: info: MYVOLUMIO Environment detected
May 27 06:56:26 volumio volumio[10063]: info: Plugin folders cleanup
May 27 06:56:26 volumio volumio[10063]: info: Scanning into folder /volumio/app/plugins/
May 27 06:56:26 volumio volumio[10063]: info: Scanning category audio_interface
May 27 06:56:26 volumio volumio[10063]: info: Scanning category miscellanea
May 27 06:56:26 volumio volumio[10063]: info: Scanning category music_service
May 27 06:56:26 volumio volumio[10063]: info: Scanning category plugins.json
May 27 06:56:26 volumio volumio[10063]: info: Scanning category system_controller
May 27 06:56:26 volumio volumio[10063]: info: Scanning category user_interface
May 27 06:56:26 volumio volumio[10063]: info: Scanning into folder /data/plugins/
May 27 06:56:26 volumio volumio[10063]: info: Plugin folders cleanup completed
May 27 06:56:26 volumio volumio[10063]: info: -------------------------------------------
May 27 06:56:26 volumio volumio[10063]: info: ----- Core plugins startup ----
May 27 06:56:26 volumio volumio[10063]: info: -------------------------------------------
May 27 06:56:26 volumio volumio[10063]: info: Loading plugins from folder /volumio/app/plugins/
May 27 06:56:26 volumio volumio[10063]: info: Adding plugin upnp to MyMusic Plugins
May 27 06:56:26 volumio volumio[10063]: info: Adding plugin airplay_emulation to MyMusic Plugins
May 27 06:56:26 volumio volumio[10063]: info: Adding plugin upnp_browser to MyMusic Plugins
May 27 06:56:26 volumio volumio[10063]: info: Loading plugins from folder /data/plugins/
May 27 06:56:26 volumio volumio[10063]: info: Loading plugin "system"...
May 27 06:56:26 volumio volumio[10063]: info: Loading plugin "appearance"...
May 27 06:56:26 volumio volumio[10063]: info: Loading plugin "network"...
May 27 06:56:26 volumio volumio[10063]: info: Refreshing Cached IP Addresses
May 27 06:56:26 volumio volumio[10063]: info: Loading plugin "services"...
May 27 06:56:26 volumio sudo[10094]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
May 27 06:56:26 volumio sudo[10094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:26 volumio volumio[10063]: info: Loading plugin "volumio5onboarding"...
May 27 06:56:26 volumio sudo[10095]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
May 27 06:56:26 volumio sudo[10095]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:26 volumio volumio[10063]: info: Loading plugin "alsa_controller"...
May 27 06:56:26 volumio sudo[10095]: pam_unix(sudo:session): session closed for user root
May 27 06:56:26 volumio sudo[10094]: pam_unix(sudo:session): session closed for user root
May 27 06:56:26 volumio sudo[10106]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
May 27 06:56:26 volumio sudo[10106]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:26 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 27 06:56:26 volumio volumio[10063]: info: Loading plugin "wizard"...
May 27 06:56:26 volumio volumio[10063]: info: Loading plugin "networkfs"...
May 27 06:56:26 volumio sudo[10106]: pam_unix(sudo:session): session closed for user root
May 27 06:56:26 volumio volumio[10063]: info: Starting Udev Watcher for removable devices
May 27 06:56:26 volumio volumio[10063]: info: Mounting Device ONtoch
May 27 06:56:26 volumio sudo[10133]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sdb1 /mnt/USB/ONtoch -o noatime,dmask=0000,fmask=0000,iocharset=utf8
May 27 06:56:26 volumio sudo[10133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:30 volumio volumio-remote-updater[734]: [2026-05-27 06:56:30] [connect] Successful connection
May 27 06:56:32 volumio ntfs-3g[10141]: Version 2022.10.3 integrated FUSE 28
May 27 06:56:32 volumio ntfs-3g[10141]: Mounted /dev/sdb1 (Read-Write, label "ONtoch", NTFS 3.1)
May 27 06:56:32 volumio ntfs-3g[10141]: Cmdline options: rw,noatime,dmask=0000,fmask=0000,iocharset=utf8
May 27 06:56:32 volumio ntfs-3g[10141]: Mount options: iocharset=utf8,allow_other,nonempty,noatime,rw,default_permissions,fsname=/dev/sdb1,blkdev,blksize=4096
May 27 06:56:32 volumio ntfs-3g[10141]: Global ownership and permissions enforced, configuration type 7
May 27 06:56:32 volumio sudo[10133]: pam_unix(sudo:session): session closed for user root
May 27 06:56:32 volumio volumio[10063]: info: Ignoring mount for partition: boot
May 27 06:56:32 volumio volumio[10063]: info: Ignoring mount for partition: volumio
May 27 06:56:32 volumio volumio[10063]: info: Ignoring mount for partition: volumio_data
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "volumio_command_line_client"...
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "upnp"...
May 27 06:56:32 volumio volumio[10063]: info: [1779839792092] Starting Upmpd Daemon
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "my_music"...
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "mpd"...
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "upnp_browser"...
May 27 06:56:32 volumio volumio[10063]: info: Starting UPNP Browser
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "alarm-clock"...
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "airplay_emulation"...
May 27 06:56:32 volumio volumio[10063]: info: Starting Shairport Sync
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "last_100"...
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "webradio"...
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "i2s_dacs"...
May 27 06:56:32 volumio volumio[10063]: info: I2S DAC not set, start Auto-detection
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "volumiodiscovery"...
May 27 06:56:32 volumio volumio[10063]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
May 27 06:56:32 volumio volumio[10063]: *** WARNING *** Please fix your application to use the native API of Avahi!
May 27 06:56:32 volumio node[10063]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
May 27 06:56:32 volumio volumio[10063]: *** WARNING *** For more information see
May 27 06:56:32 volumio volumio[10063]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
May 27 06:56:32 volumio volumio[10063]: *** WARNING *** Please fix your application to use the native API of Avahi!
May 27 06:56:32 volumio volumio[10063]: *** WARNING *** For more information see
May 27 06:56:32 volumio node[10063]: *** WARNING *** Please fix your application to use the native API of Avahi!
May 27 06:56:32 volumio node[10063]: *** WARNING *** For more information see
May 27 06:56:32 volumio node[10063]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
May 27 06:56:32 volumio node[10063]: *** WARNING *** Please fix your application to use the native API of Avahi!
May 27 06:56:32 volumio node[10063]: *** WARNING *** For more information see
May 27 06:56:32 volumio volumio[10063]: info: Applying required configuration parameters for plugin volumiodiscovery
May 27 06:56:32 volumio volumio[10063]: info: Discovery: Started advertising with name: Volumio
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "outputs"...
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "albumart"...
May 27 06:56:32 volumio volumio[10063]: info: Plugin example_plugin is not enabled
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "inputs"...
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "updater_comm"...
May 27 06:56:32 volumio volumio[10063]: info: Plugin mpdemulation is not enabled
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "rest_api"...
May 27 06:56:32 volumio volumio[10147]: Forking 1 albumart workers
May 27 06:56:32 volumio volumio[10063]: info: Loading plugin "websocket"...
May 27 06:56:32 volumio volumio[10063]: info: Starting Socket.io Server version 1.7.4
May 27 06:56:32 volumio volumio[10063]: info: Loading i18n strings for locale ru
May 27 06:56:32 volumio volumio[10063]: Updating browse sources language
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::initPlayerControls
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
May 27 06:56:32 volumio volumio[10063]: Express server listening on port 3000
May 27 06:56:32 volumio volumio[10063]: [Metrics] WebUI: 7s 184.63ms
May 27 06:56:32 volumio volumio[10063]: info: Setting Device type: x86
May 27 06:56:32 volumio volumio[10063]: info: CoreStateMachine::resetVolumioState
May 27 06:56:32 volumio volumio[10063]: info: CoreStateMachine::getcurrentVolume
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::volumioRetrievevolume
May 27 06:56:32 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:56:33 volumio volumio[10063]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt'
May 27 06:56:33 volumio volumio[10063]: info: Completed loading Core Plugins
May 27 06:56:33 volumio volumio[10063]: info: Preparing to generate the ALSA configuration file
May 27 06:56:33 volumio volumio[10063]: info: Volumio Network Manager: Network status updated: 1
May 27 06:56:33 volumio volumio[10063]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan
May 27 06:56:33 volumio volumio[10063]: wlan0 Interface doesn't support scanning.
May 27 06:56:33 volumio volumio[10063]: info: Cannot use regular scanning, forcing with ap-force
May 27 06:56:33 volumio sudo[10175]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force
May 27 06:56:33 volumio sudo[10175]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:33 volumio sudo[10175]: pam_unix(sudo:session): session closed for user root
May 27 06:56:33 volumio volumio[10063]: command failed: No such device (-19)
May 27 06:56:33 volumio volumio[10063]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force
May 27 06:56:33 volumio volumio[10063]: command failed: No such device (-19)
May 27 06:56:33 volumio volumio[10063]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision
May 27 06:56:33 volumio volumio[10063]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf
May 27 06:56:33 volumio volumio[10063]: info: Reading ALSA contributions from plugins.
May 27 06:56:33 volumio volumio[10063]: verbose: New Socket.io Connection to 192.168.1.69 from 192.168.1.54 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/148.0.0.0 Safari/537.36 Edg/148.0.0.0 Engine version: 3 Transport: polling Total Clients: 1
May 27 06:56:33 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:33 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:33 volumio volumio[10063]: info: CoreStateMachine::updateTrackBlock
May 27 06:56:33 volumio volumio[10063]: info: CorePlayQueue::getTrackBlock
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::volumioRetrievevolume
May 27 06:56:33 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2
May 27 06:56:33 volumio volumio[10063]: info: Reloading queue from file
May 27 06:56:33 volumio volumio[10063]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 2
May 27 06:56:33 volumio volumio[10063]: info: CoreStateMachine::setRepeat null single undefined
May 27 06:56:33 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:33 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:33 volumio volumio[10063]: info: CoreStateMachine::setRandom null
May 27 06:56:33 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:33 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:33 volumio volumio[10063]: verbose: New Socket.io Connection to 192.168.1.69 from 192.168.1.54 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/148.0.0.0 Safari/537.36 Edg/148.0.0.0 Engine version: 3 Transport: polling Total Clients: 3
May 27 06:56:33 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:33 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:33 volumio volumio[10063]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 4
May 27 06:56:33 volumio volumio-remote-updater[734]: [2026-05-27 06:56:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1779839790 101
May 27 06:56:33 volumio volumio[10157]: Starting albumart workers
May 27 06:56:33 volumio volumio[10063]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 5
May 27 06:56:33 volumio volumio[10063]: verbose: New Socket.io Connection to 192.168.1.69 from 192.168.1.54 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/148.0.0.0 Safari/537.36 Edg/148.0.0.0 Engine version: 3 Transport: polling Total Clients: 6
May 27 06:56:33 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7
May 27 06:56:33 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7
May 27 06:56:33 volumio volumio[10063]: info: Asound.conf file unchanged, so no further update is needed
May 27 06:56:33 volumio volumio[10063]: info: Output device has changed, restarting MPD
May 27 06:56:33 volumio volumio[10063]: info: Output device has changed, restarting Shairport Sync
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:56:33 volumio sudo[10192]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
May 27 06:56:33 volumio sudo[10192]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:33 volumio sudo[10190]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
May 27 06:56:33 volumio sudo[10190]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:33 volumio sudo[10190]: pam_unix(sudo:session): session closed for user root
May 27 06:56:33 volumio volumio[10063]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
May 27 06:56:33 volumio volumio[10063]: info: ___________ START PLUGINS ___________
May 27 06:56:33 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
May 27 06:56:33 volumio volumio[10063]: info: ControllerMpd::onStart: Initializing MPD
May 27 06:56:33 volumio volumio[10063]: info: Creating MPD Configuration file
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 27 06:56:33 volumio volumio[10063]: info: [1779839793350] CoreMusicLibrary::Adding element Медиа-серверы
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 27 06:56:33 volumio volumio[10063]: info: UPNP Browser: Client initialized successfully
May 27 06:56:33 volumio upmpdcli[1800]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0
May 27 06:56:33 volumio sudo[10204]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
May 27 06:56:33 volumio systemd[1]: mpd.service: Deactivated successfully.
May 27 06:56:33 volumio sudo[10204]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
May 27 06:56:33 volumio systemd[1]: mpd.service: Consumed 7.053s CPU time.
May 27 06:56:33 volumio sudo[10202]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
May 27 06:56:33 volumio sudo[10202]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:33 volumio systemd[1]: mpd.socket: Deactivated successfully.
May 27 06:56:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
May 27 06:56:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
May 27 06:56:33 volumio sudo[10200]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service
May 27 06:56:33 volumio sudo[10200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:56:33 volumio sudo[10202]: pam_unix(sudo:session): session closed for user root
May 27 06:56:33 volumio volumio[10063]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
May 27 06:56:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:56:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
May 27 06:56:33 volumio volumio[10063]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
May 27 06:56:33 volumio systemd[1]: mpd.service: Deactivated successfully.
May 27 06:56:33 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
May 27 06:56:33 volumio systemd[1]: mpd.socket: Deactivated successfully.
May 27 06:56:33 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
May 27 06:56:33 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 27 06:56:33 volumio volumio[10063]: info: [1779839793445] CoreMusicLibrary::Adding element Last_100
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
May 27 06:56:33 volumio volumio[10063]: info: [1779839793447] CoreMusicLibrary::Adding element Webradio
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 27 06:56:33 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 27 06:56:33 volumio volumio[10063]: info: Initializing BBC Radios
May 27 06:56:33 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
May 27 06:56:33 volumio sudo[10200]: pam_unix(sudo:session): session closed for user root
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: Volumio Calling Home
May 27 06:56:33 volumio sudo[10219]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
May 27 06:56:33 volumio sudo[10219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
May 27 06:56:33 volumio sudo[10219]: pam_unix(sudo:session): session closed for user root
May 27 06:56:33 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 7
May 27 06:56:33 volumio volumio[10063]: info: MPD Permissions set
May 27 06:56:33 volumio volumio[10063]: info: MPD Permissions set
May 27 06:56:33 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7
May 27 06:56:33 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 27 06:56:33 volumio volumio[10063]: info: Volumio called home
May 27 06:56:33 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8
May 27 06:56:33 volumio volumio[10063]: info: Starting Shairport Sync
May 27 06:56:33 volumio volumio[10063]: info: Starting Shairport Sync
May 27 06:56:33 volumio volumio[10063]: info: Starting Shairport Sync
May 27 06:56:33 volumio sudo[10265]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
May 27 06:56:33 volumio sudo[10265]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:33 volumio sudo[10266]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
May 27 06:56:33 volumio volumio[10063]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:33 volumio volumio[10063]: info: Discovery: Restarting Browsing
May 27 06:56:33 volumio sudo[10268]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
May 27 06:56:33 volumio sudo[10268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:33 volumio sudo[10266]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:33 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8
May 27 06:56:33 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
May 27 06:56:33 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
May 27 06:56:33 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
May 27 06:56:33 volumio systemd[1]: shairport-sync.service: Consumed 1.847s CPU time.
May 27 06:56:33 volumio volumio[10063]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:33 volumio volumio[10063]: info: Discovery: Restarting Browsing
May 27 06:56:33 volumio volumio[10063]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:56:33 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8
May 27 06:56:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
May 27 06:56:33 volumio sudo[10265]: pam_unix(sudo:session): session closed for user root
May 27 06:56:33 volumio sudo[10268]: pam_unix(sudo:session): session closed for user root
May 27 06:56:33 volumio volumio[10063]: info: CoreCommandRouter::volumioGetState
May 27 06:56:33 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:33 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
May 27 06:56:33 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
May 27 06:56:33 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
May 27 06:56:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
May 27 06:56:33 volumio sudo[10266]: pam_unix(sudo:session): session closed for user root
May 27 06:56:34 volumio volumio[10063]: info: Shairport-Sync Started
May 27 06:56:34 volumio volumio[10063]: Error adding Membership: Error: addMembership EINVAL
May 27 06:56:34 volumio volumio[10063]: info: Shairport-Sync Started
May 27 06:56:34 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8
May 27 06:56:34 volumio volumio[10063]: info: Shairport-Sync Started
May 27 06:56:34 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8
May 27 06:56:34 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8
May 27 06:56:34 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8
May 27 06:56:34 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8
May 27 06:56:34 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8
May 27 06:56:34 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8
May 27 06:56:34 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8
May 27 06:56:34 volumio volumio[10063]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 8
May 27 06:56:34 volumio mpd[10236]: 2026-05-27T06:56:34 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
May 27 06:56:34 volumio systemd[1]: Started mpd.service - Music Player Daemon.
May 27 06:56:34 volumio sudo[10192]: pam_unix(sudo:session): session closed for user root
May 27 06:56:34 volumio sudo[10204]: pam_unix(sudo:session): session closed for user root
May 27 06:56:34 volumio upmpdcli[1800]: :3:../src/mpdcli.cxx:148::MPDCli::startEventLoop: already started
May 27 06:56:34 volumio volumio[10063]: info: Completed starting Core Plugins
May 27 06:56:34 volumio volumio[10063]: info: -------------------------------------------
May 27 06:56:34 volumio volumio[10063]: info: ----- MyVolumio plugins startup ----
May 27 06:56:34 volumio volumio[10063]: info: -------------------------------------------
May 27 06:56:34 volumio volumio[10063]: info: [MyVolumio PluginManager] Fetching plans data....
May 27 06:56:34 volumio volumio[10063]: error: MPD error: The expression evaluated to a falsy value:
May 27 06:56:34 volumio volumio[10063]: assert.ok(self.idling)
May 27 06:56:34 volumio volumio[10063]: error: The expression evaluated to a falsy value:
May 27 06:56:34 volumio volumio[10063]: assert.ok(self.idling)
May 27 06:56:34 volumio volumio[10063]: info: MPD running with PID10236
May 27 06:56:34 volumio volumio[10063]: ,establishing connection
May 27 06:56:34 volumio volumio[10063]: error: updateQueue error: null
May 27 06:56:34 volumio volumio[10063]: error: updateQueue error: null
May 27 06:56:34 volumio volumio[10063]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9
May 27 06:56:34 volumio volumio[10063]: info: CoreCommandRouter::volumioGetVisibleSources
May 27 06:56:34 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 27 06:56:34 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
May 27 06:56:34 volumio volumio[10063]: info: CoreCommandRouter::volumioGetState
May 27 06:56:34 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:37 volumio volumio[10063]: verbose: New Socket.io Connection to 192.168.1.69 from 192.168.1.54 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/148.0.0.0 Safari/537.36 Edg/148.0.0.0 Engine version: 3 Transport: polling Total Clients: 10
May 27 06:56:37 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:56:37 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:56:37 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:56:37 volumio volumio[10063]: info: CoreCommandRouter::volumioGetVisibleSources
May 27 06:56:37 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
May 27 06:56:37 volumio volumio[10063]: info: CoreCommandRouter::volumioGetState
May 27 06:56:37 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:37 volumio volumio[10063]: info: CoreCommandRouter::volumioGetQueue
May 27 06:56:37 volumio volumio[10063]: info: CoreStateMachine::getQueue
May 27 06:56:37 volumio volumio[10063]: info: CorePlayQueue::getQueue
May 27 06:56:37 volumio volumio[10063]: info: Listing playlists
May 27 06:56:37 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
May 27 06:56:37 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::volumioPlay
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::play index undefined
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::setConsumeUpdateService undefined
May 27 06:56:38 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::startPlaybackTimer
May 27 06:56:38 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:38 volumio volumio[10063]: info: [1779839798502] ControllerWebradio::clearAddPlayTrack
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand stop
May 27 06:56:38 volumio volumio[10063]: info: sendMpdCommand stop took 1 milliseconds
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand clear
May 27 06:56:38 volumio volumio[10063]: info: sendMpdCommand clear took 1 milliseconds
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand load "http://stream.funradio.sk:8000/80-90-128.mp3"
May 27 06:56:38 volumio volumio[10063]: info:
May 27 06:56:38 volumio volumio[10063]: ---------------------------- MPD announces system playlist update
May 27 06:56:38 volumio volumio[10063]: info: Ignoring MPD Status Update
May 27 06:56:38 volumio volumio[10063]: info:
May 27 06:56:38 volumio volumio[10063]: ---------------------------- MPD announces system playlist update
May 27 06:56:38 volumio volumio[10063]: info: Ignoring MPD Status Update
May 27 06:56:38 volumio volumio[10063]: info:
May 27 06:56:38 volumio volumio[10063]: ---------------------------- MPD announces system playlist update
May 27 06:56:38 volumio volumio[10063]: info: Ignoring MPD Status Update
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand add "http://stream.funradio.sk:8000/80-90-128.mp3"
May 27 06:56:38 volumio volumio[10063]: error: updateQueue error: null
May 27 06:56:38 volumio volumio[10063]: error: updateQueue error: null
May 27 06:56:38 volumio volumio[10063]: error: updateQueue error: null
May 27 06:56:38 volumio volumio[10063]: info:
May 27 06:56:38 volumio volumio[10063]: ---------------------------- MPD announces system playlist update
May 27 06:56:38 volumio volumio[10063]: info: Ignoring MPD Status Update
May 27 06:56:38 volumio volumio[10063]: info: ------------------------------ 246ms
May 27 06:56:38 volumio volumio[10063]: info: ------------------------------ 246ms
May 27 06:56:38 volumio volumio[10063]: info: ------------------------------ 245ms
May 27 06:56:38 volumio volumio[10063]: info: sendMpdCommand add "http://stream.funradio.sk:8000/80-90-128.mp3" took 1 milliseconds
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::setConsumeUpdateService mpd
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand play
May 27 06:56:38 volumio volumio[10063]: info:
May 27 06:56:38 volumio volumio[10063]: ---------------------------- MPD announces system playlist update
May 27 06:56:38 volumio volumio[10063]: info: Ignoring MPD Status Update
May 27 06:56:38 volumio volumio[10063]: info: ------------------------------ 3ms
May 27 06:56:38 volumio volumio[10063]: info: sendMpdCommand play took 2 milliseconds
May 27 06:56:38 volumio volumio[10063]: info: ------------------------------ 2ms
May 27 06:56:38 volumio volumio[10063]: info:
May 27 06:56:38 volumio volumio[10063]: ---------------------------- MPD announces system playlist update
May 27 06:56:38 volumio volumio[10063]: info: Ignoring MPD Status Update
May 27 06:56:38 volumio volumio[10063]: info: ------------------------------ 1ms
May 27 06:56:38 volumio volumio[10063]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:38 volumio volumio[10063]: info: Discovery: Restarting Browsing
May 27 06:56:38 volumio volumio[10063]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:38 volumio volumio[10063]: info: Discovery: Restarting Browsing
May 27 06:56:38 volumio volumio[10063]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:56:38 volumio volumio[10063]: info:
May 27 06:56:38 volumio volumio[10063]: ---------------------------- MPD announces state update: player
May 27 06:56:38 volumio volumio[10063]: info: ControllerMpd::getState
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:56:38 volumio volumio[10063]: info:
May 27 06:56:38 volumio volumio[10063]: ---------------------------- MPD announces state update: player
May 27 06:56:38 volumio volumio[10063]: info: ControllerMpd::getState
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:56:38 volumio volumio[10063]: info:
May 27 06:56:38 volumio volumio[10063]: ---------------------------- MPD announces state update: player
May 27 06:56:38 volumio volumio[10063]: info: ControllerMpd::getState
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:56:38 volumio volumio[10063]: info:
May 27 06:56:38 volumio volumio[10063]: ---------------------------- MPD announces state update: player
May 27 06:56:38 volumio volumio[10063]: info: sendMpdCommand status took 10 milliseconds
May 27 06:56:38 volumio volumio[10063]: info: sendMpdCommand status took 10 milliseconds
May 27 06:56:38 volumio volumio[10063]: info: sendMpdCommand status took 10 milliseconds
May 27 06:56:38 volumio volumio[10063]: info: ControllerMpd::getState
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::parseState
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::parseState
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::parseState
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:56:38 volumio volumio[10063]: info: sendMpdCommand status took 2 milliseconds
May 27 06:56:38 volumio volumio[10063]: info: sendMpdCommand playlistinfo took 1 milliseconds
May 27 06:56:38 volumio volumio[10063]: info: sendMpdCommand playlistinfo took 1 milliseconds
May 27 06:56:38 volumio volumio[10063]: info: sendMpdCommand playlistinfo took 1 milliseconds
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::parseState
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::parseTrackInfo
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::parseTrackInfo
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::parseTrackInfo
May 27 06:56:38 volumio volumio[10063]: info: ControllerMpd::pushState
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::servicePushState
May 27 06:56:38 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:38 volumio volumio[10063]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"80-90-128.mp3","artist":null,"album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:56:38 volumio volumio[10063]: verbose: CURRENT POSITION 0
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::syncState stateService play
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::syncState currentStatus stop
May 27 06:56:38 volumio volumio[10063]: info: ControllerMpd::pushState
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::servicePushState
May 27 06:56:38 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:38 volumio volumio[10063]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"80-90-128.mp3","artist":null,"album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:56:38 volumio volumio[10063]: verbose: CURRENT POSITION 0
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::syncState stateService play
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::syncState currentStatus play
May 27 06:56:38 volumio volumio[10063]: info: Received an update from plugin. extracting info from payload
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:38 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:38 volumio volumio[10063]: info: ControllerMpd::pushState
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::servicePushState
May 27 06:56:38 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:38 volumio volumio[10063]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"80-90-128.mp3","artist":null,"album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:56:38 volumio volumio[10063]: verbose: CURRENT POSITION 0
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::syncState stateService play
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::syncState currentStatus play
May 27 06:56:38 volumio volumio[10063]: info: Received an update from plugin. extracting info from payload
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:38 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:38 volumio volumio[10063]: info: ------------------------------ 23ms
May 27 06:56:38 volumio volumio[10063]: info: ------------------------------ 30ms
May 27 06:56:38 volumio volumio[10063]: info: ------------------------------ 29ms
May 27 06:56:38 volumio volumio[10063]: info:
May 27 06:56:38 volumio volumio[10063]: ---------------------------- MPD announces state update: player
May 27 06:56:38 volumio volumio[10063]: info: ControllerMpd::getState
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:56:38 volumio volumio[10063]: info:
May 27 06:56:38 volumio volumio[10063]: ---------------------------- MPD announces state update: player
May 27 06:56:38 volumio volumio[10063]: info: ControllerMpd::getState
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:56:38 volumio volumio[10063]: info: sendMpdCommand playlistinfo took 18 milliseconds
May 27 06:56:38 volumio volumio[10063]: info: sendMpdCommand status took 1 milliseconds
May 27 06:56:38 volumio volumio[10063]: info: sendMpdCommand status took 1 milliseconds
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::parseTrackInfo
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::parseState
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::parseState
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:56:38 volumio volumio[10063]: info: ControllerMpd::pushState
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::servicePushState
May 27 06:56:38 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:38 volumio volumio[10063]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"80-90-128.mp3","artist":null,"album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:56:38 volumio volumio[10063]: verbose: CURRENT POSITION 0
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::syncState stateService play
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::syncState currentStatus play
May 27 06:56:38 volumio volumio[10063]: info: Received an update from plugin. extracting info from payload
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:38 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:38 volumio volumio[10063]: info: ------------------------------ 34ms
May 27 06:56:38 volumio volumio[10063]: info: sendMpdCommand playlistinfo took 15 milliseconds
May 27 06:56:38 volumio volumio[10063]: info: sendMpdCommand playlistinfo took 16 milliseconds
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::parseTrackInfo
May 27 06:56:38 volumio volumio[10063]: verbose: ControllerMpd::parseTrackInfo
May 27 06:56:38 volumio volumio[10063]: info: ControllerMpd::pushState
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::servicePushState
May 27 06:56:38 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:38 volumio volumio[10063]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"80-90-128.mp3","artist":null,"album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:56:38 volumio volumio[10063]: verbose: CURRENT POSITION 0
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::syncState stateService play
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::syncState currentStatus play
May 27 06:56:38 volumio volumio[10063]: info: Received an update from plugin. extracting info from payload
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:38 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:38 volumio volumio[10063]: info: ControllerMpd::pushState
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::servicePushState
May 27 06:56:38 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:38 volumio volumio[10063]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"80-90-128.mp3","artist":null,"album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:56:38 volumio volumio[10063]: verbose: CURRENT POSITION 0
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::syncState stateService play
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::syncState currentStatus play
May 27 06:56:38 volumio volumio[10063]: info: Received an update from plugin. extracting info from payload
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:38 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:38 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:38 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:39 volumio volumio[10063]: info: ------------------------------ 43ms
May 27 06:56:39 volumio volumio[10063]: info: ------------------------------ 42ms
May 27 06:56:39 volumio volumio[10063]: info:
May 27 06:56:39 volumio volumio[10063]: ---------------------------- MPD announces system playlist update
May 27 06:56:39 volumio volumio[10063]: info: Ignoring MPD Status Update
May 27 06:56:39 volumio volumio[10063]: info:
May 27 06:56:39 volumio volumio[10063]: ---------------------------- MPD announces state update: player
May 27 06:56:39 volumio volumio[10063]: info: ControllerMpd::getState
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:56:39 volumio volumio[10063]: info:
May 27 06:56:39 volumio volumio[10063]: ---------------------------- MPD announces system playlist update
May 27 06:56:39 volumio volumio[10063]: info: Ignoring MPD Status Update
May 27 06:56:39 volumio volumio[10063]: info:
May 27 06:56:39 volumio volumio[10063]: ---------------------------- MPD announces state update: player
May 27 06:56:39 volumio volumio[10063]: info: ControllerMpd::getState
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:56:39 volumio volumio[10063]: info:
May 27 06:56:39 volumio volumio[10063]: ---------------------------- MPD announces system playlist update
May 27 06:56:39 volumio volumio[10063]: info: Ignoring MPD Status Update
May 27 06:56:39 volumio volumio[10063]: info:
May 27 06:56:39 volumio volumio[10063]: ---------------------------- MPD announces state update: player
May 27 06:56:39 volumio volumio[10063]: info:
May 27 06:56:39 volumio volumio[10063]: ---------------------------- MPD announces system playlist update
May 27 06:56:39 volumio volumio[10063]: info: Ignoring MPD Status Update
May 27 06:56:39 volumio volumio[10063]: info:
May 27 06:56:39 volumio volumio[10063]: ---------------------------- MPD announces state update: player
May 27 06:56:39 volumio volumio[10063]: info: ControllerMpd::getState
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:56:39 volumio volumio[10063]: info: ------------------------------ 6ms
May 27 06:56:39 volumio volumio[10063]: info: ControllerMpd::getState
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:56:39 volumio volumio[10063]: info: sendMpdCommand status took 5 milliseconds
May 27 06:56:39 volumio volumio[10063]: info: ------------------------------ 4ms
May 27 06:56:39 volumio volumio[10063]: info: sendMpdCommand status took 2 milliseconds
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::parseState
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::parseState
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:56:39 volumio volumio[10063]: info:
May 27 06:56:39 volumio volumio[10063]: ---------------------------- MPD announces system playlist update
May 27 06:56:39 volumio volumio[10063]: info: Ignoring MPD Status Update
May 27 06:56:39 volumio volumio[10063]: info:
May 27 06:56:39 volumio volumio[10063]: ---------------------------- MPD announces state update: player
May 27 06:56:39 volumio volumio[10063]: info: ControllerMpd::getState
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:56:39 volumio volumio[10063]: info:
May 27 06:56:39 volumio volumio[10063]: ---------------------------- MPD announces system playlist update
May 27 06:56:39 volumio volumio[10063]: info: Ignoring MPD Status Update
May 27 06:56:39 volumio volumio[10063]: info:
May 27 06:56:39 volumio volumio[10063]: ---------------------------- MPD announces state update: player
May 27 06:56:39 volumio volumio[10063]: info: ControllerMpd::getState
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand status
May 27 06:56:39 volumio volumio[10063]: info: ------------------------------ 8ms
May 27 06:56:39 volumio volumio[10063]: info: sendMpdCommand status took 8 milliseconds
May 27 06:56:39 volumio volumio[10063]: info: ------------------------------ 8ms
May 27 06:56:39 volumio volumio[10063]: info: sendMpdCommand status took 7 milliseconds
May 27 06:56:39 volumio volumio[10063]: info: sendMpdCommand playlistinfo took 4 milliseconds
May 27 06:56:39 volumio volumio[10063]: info: sendMpdCommand playlistinfo took 3 milliseconds
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::parseState
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::parseState
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::parseTrackInfo
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::parseTrackInfo
May 27 06:56:39 volumio volumio[10063]: info: ControllerMpd::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::servicePushState
May 27 06:56:39 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:39 volumio volumio[10063]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Depeche Mode - I Feel You","artist":"FUN Radio 80-90","album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:56:39 volumio volumio[10063]: verbose: CURRENT POSITION 0
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::syncState stateService play
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::syncState currentStatus play
May 27 06:56:39 volumio volumio[10063]: info: Received an update from plugin. extracting info from payload
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:39 volumio volumio[10063]: info: ControllerMpd::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::servicePushState
May 27 06:56:39 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:39 volumio volumio[10063]: verbose: STATE SERVICE {"status":"play","position":0,"seek":91,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Depeche Mode - I Feel You","artist":"FUN Radio 80-90","album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:56:39 volumio volumio[10063]: verbose: CURRENT POSITION 0
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::syncState stateService play
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::syncState currentStatus play
May 27 06:56:39 volumio volumio[10063]: info: Received an update from plugin. extracting info from payload
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:39 volumio volumio[10063]: info: ------------------------------ 42ms
May 27 06:56:39 volumio volumio[10063]: info: ------------------------------ 43ms
May 27 06:56:39 volumio volumio[10063]: info: ------------------------------ 37ms
May 27 06:56:39 volumio volumio[10063]: info: sendMpdCommand status took 38 milliseconds
May 27 06:56:39 volumio volumio[10063]: info: ------------------------------ 37ms
May 27 06:56:39 volumio volumio[10063]: info: sendMpdCommand status took 37 milliseconds
May 27 06:56:39 volumio volumio[10063]: info: sendMpdCommand playlistinfo took 36 milliseconds
May 27 06:56:39 volumio volumio[10063]: info: sendMpdCommand playlistinfo took 36 milliseconds
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::parseState
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::parseState
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand playlistinfo
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::parseTrackInfo
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::parseTrackInfo
May 27 06:56:39 volumio volumio[10063]: info: ControllerMpd::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::servicePushState
May 27 06:56:39 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:39 volumio volumio[10063]: verbose: STATE SERVICE {"status":"play","position":0,"seek":91,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Depeche Mode - I Feel You","artist":"FUN Radio 80-90","album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:56:39 volumio volumio[10063]: verbose: CURRENT POSITION 0
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::syncState stateService play
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::syncState currentStatus play
May 27 06:56:39 volumio volumio[10063]: info: Received an update from plugin. extracting info from payload
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:39 volumio volumio[10063]: info: ControllerMpd::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::servicePushState
May 27 06:56:39 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:39 volumio volumio[10063]: verbose: STATE SERVICE {"status":"play","position":0,"seek":91,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Depeche Mode - I Feel You","artist":"FUN Radio 80-90","album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:56:39 volumio volumio[10063]: verbose: CURRENT POSITION 0
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::syncState stateService play
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::syncState currentStatus play
May 27 06:56:39 volumio volumio[10063]: info: Received an update from plugin. extracting info from payload
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:39 volumio volumio[10063]: info: ------------------------------ 85ms
May 27 06:56:39 volumio volumio[10063]: info: ------------------------------ 85ms
May 27 06:56:39 volumio volumio[10063]: info: sendMpdCommand playlistinfo took 59 milliseconds
May 27 06:56:39 volumio volumio[10063]: info: sendMpdCommand playlistinfo took 86 milliseconds
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::parseTrackInfo
May 27 06:56:39 volumio volumio[10063]: verbose: ControllerMpd::parseTrackInfo
May 27 06:56:39 volumio volumio[10063]: info: ControllerMpd::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::servicePushState
May 27 06:56:39 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:39 volumio volumio[10063]: verbose: STATE SERVICE {"status":"play","position":0,"seek":136,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Depeche Mode - I Feel You","artist":"FUN Radio 80-90","album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:56:39 volumio volumio[10063]: verbose: CURRENT POSITION 0
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::syncState stateService play
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::syncState currentStatus play
May 27 06:56:39 volumio volumio[10063]: info: Received an update from plugin. extracting info from payload
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:39 volumio volumio[10063]: info: ControllerMpd::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::servicePushState
May 27 06:56:39 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:39 volumio volumio[10063]: verbose: STATE SERVICE {"status":"play","position":0,"seek":136,"duration":0,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Depeche Mode - I Feel You","artist":"FUN Radio 80-90","album":null,"uri":"http://stream.funradio.sk:8000/80-90-128.mp3","trackType":"mp3"}
May 27 06:56:39 volumio volumio[10063]: verbose: CURRENT POSITION 0
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::syncState stateService play
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::syncState currentStatus play
May 27 06:56:39 volumio volumio[10063]: info: Received an update from plugin. extracting info from payload
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:39 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:39 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:39 volumio volumio[10063]: info: ------------------------------ 170ms
May 27 06:56:39 volumio volumio[10063]: info: ------------------------------ 172ms
May 27 06:56:41 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:56:42 volumio sudo[10335]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
May 27 06:56:42 volumio sudo[10335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:42 volumio sudo[10335]: pam_unix(sudo:session): session closed for user root
May 27 06:56:42 volumio sudo[10337]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
May 27 06:56:42 volumio sudo[10337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:42 volumio sudo[10337]: pam_unix(sudo:session): session closed for user root
May 27 06:56:42 volumio sudo[10341]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
May 27 06:56:42 volumio sudo[10341]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:42 volumio sudo[10341]: pam_unix(sudo:session): session closed for user root
May 27 06:56:42 volumio volumio[10063]: info: Upmpdcli Daemon Started
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
May 27 06:56:43 volumio volumio[10063]: info: Adding plugin bluetooth to MyMusic Plugins
May 27 06:56:43 volumio volumio[10063]: info: Adding plugin multiroom to MyMusic Plugins
May 27 06:56:43 volumio volumio[10063]: info: Adding plugin metavolumio to MyMusic Plugins
May 27 06:56:43 volumio volumio[10063]: info: Adding plugin cd_controller to MyMusic Plugins
May 27 06:56:43 volumio volumio[10063]: info: Adding plugin qobuzconnect to MyMusic Plugins
May 27 06:56:43 volumio volumio[10063]: info: Adding plugin smart_inputs to MyMusic Plugins
May 27 06:56:43 volumio volumio[10063]: info: Adding plugin tidalconnect to MyMusic Plugins
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
May 27 06:56:43 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:56:43 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
May 27 06:56:43 volumio volumio[10063]: info: Starting MyVolumio Remote Streaming Endpoints
May 27 06:56:43 volumio volumio[10063]: info: MyVolumio not started
May 27 06:56:43 volumio volumio[10063]: info: Initializing device activation check
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
May 27 06:56:43 volumio volumio[10063]: info: Streaming services startup
May 27 06:56:43 volumio volumio[10063]: info: Starting Streaming Daemon
May 27 06:56:43 volumio sudo[10348]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
May 27 06:56:43 volumio sudo[10348]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
May 27 06:56:43 volumio volumio[10063]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
May 27 06:56:43 volumio sudo[10348]: pam_unix(sudo:session): session closed for user root
May 27 06:56:43 volumio volumio[10063]: error: Cannot start Volumio Streaming Daemon
May 27 06:56:43 volumio volumio[10063]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
May 27 06:56:43 volumio volumio[10063]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
May 27 06:56:43 volumio volumio[10063]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:43 volumio volumio[10063]: info: Discovery: Restarting Browsing
May 27 06:56:43 volumio volumio[10063]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:43 volumio volumio[10063]: info: Discovery: Restarting Browsing
May 27 06:56:43 volumio volumio[10063]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:56:45 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:56:48 volumio volumio[10063]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:48 volumio volumio[10063]: info: Discovery: Restarting Browsing
May 27 06:56:48 volumio volumio[10063]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:48 volumio volumio[10063]: info: Discovery: Restarting Browsing
May 27 06:56:48 volumio volumio[10063]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:56:49 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
May 27 06:56:54 volumio volumio[10063]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:54 volumio volumio[10063]: info: Discovery: Restarting Browsing
May 27 06:56:54 volumio volumio[10063]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007
May 27 06:56:54 volumio volumio[10063]: info: Discovery: Restarting Browsing
May 27 06:56:54 volumio volumio[10063]: info: Discovery: Restart already pending, ignoring duplicate call
May 27 06:56:57 volumio volumio[10063]: info: Preload queue cleared
May 27 06:56:57 volumio volumio[10063]: info: CoreCommandRouter::volumioReplaceandPlayItems
May 27 06:56:57 volumio volumio[10063]: info: CoreStateMachine::ClearQueue
May 27 06:56:57 volumio volumio[10063]: info: CoreStateMachine::stop
May 27 06:56:57 volumio volumio[10063]: info: CoreStateMachine::setConsumeUpdateService undefined
May 27 06:56:57 volumio volumio[10063]: info: CoreStateMachine::stPlaybackTimer
May 27 06:56:57 volumio volumio[10063]: info: CoreStateMachine::updateTrackBlock
May 27 06:56:57 volumio volumio[10063]: info: CorePlayQueue::getTrackBlock
May 27 06:56:57 volumio volumio[10063]: info: CoreStateMachine::pushState
May 27 06:56:57 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:57 volumio volumio[10063]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
May 27 06:56:57 volumio volumio[10063]: info: CoreCommandRouter::volumioPushState
May 27 06:56:57 volumio volumio[10063]: info: CoreStateMachine::serviceStop
May 27 06:56:57 volumio volumio[10063]: info: CorePlayQueue::getTrack 0
May 27 06:56:57 volumio volumio[10063]: info: CoreCommandRouter::serviceStop
May 27 06:56:57 volumio volumio[10063]: info: [1779839817046] ControllerWebradio::stop
May 27 06:56:57 volumio volumio[10063]: verbose: ControllerMpd::sendMpdCommand stop
May 27 06:56:57 volumio volumio[10063]: info: CorePlayQueue::clearPlayQueue
May 27 06:56:57 volumio volumio[10063]: info: CorePlayQueue::saveQueue
May 27 06:56:57 volumio volumio[10063]: info: CoreCommandRouter::volumioPushQueue
May 27 06:56:57 volumio volumio[10063]: info: CoreStateMachine::addQueueItems
May 27 06:56:57 volumio volumio[10063]: info: CorePlayQueue::addQueueItems
May 27 06:56:57 volumio volumio[10063]: info: Preload queue cleared
May 27 06:56:57 volumio volumio[10063]: info: Adding Item to queue: music-library/USB/ONtoch/RAINBOW/Rainbow – Ritchie Blackmore's Rainbow
May 27 06:56:57 volumio volumio[10063]: info: Exploding uri music-library/USB/ONtoch/RAINBOW/Rainbow – Ritchie Blackmore's Rainbow in service mpd
May 27 06:56:57 volumio volumio[10063]: info: ALBUMART /albumart?cacheid=521&web=//medium&path=%2Fmnt%2FUSB%2FONtoch%2FRAINBOW%2FRainbow%20%E2%80%8E%E2%80%93%20Ritchie%20Blackmore's%20Rainbow%2FRitchie%20Blackmore's%20Rainbow%201975%20.cue&metadata=false
May 27 06:56:57 volumio volumio[10063]: info: URI /mnt/USB/ONtoch/RAINBOW/Rainbow – Ritchie Blackmore's Rainbow/Ritchie Blackmore's Rainbow 1975 .cue
May 27 06:56:57 volumio volumio[10063]: info: ALBUMART /albumart?cacheid=521&web=//medium&path=%2Fmnt%2FUSB%2FONtoch%2FRAINBOW%2FRainbow%20%E2%80%8E%E2%80%93%20Ritchie%20Blackmore's%20Rainbow%2FRitchie%20Blackmore's%20Rainbow%201975%20.cue&metadata=false
May 27 06:56:57 volumio volumio[10063]: info: URI /mnt/USB/ONtoch/RAINBOW/Rainbow – Ritchie Blackmore's Rainbow/Ritchie Blackmore's Rainbow 1975 .cue
May 27 06:56:57 volumio volumio[10063]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 27 06:56:57 volumio volumio[10063]: Error: Unable to resolve or reject the same promise twice
May 27 06:56:57 volumio volumio[10063]: at Promise.resolve (/volumio/node_modules/kew/kew.js:140:43)
May 27 06:56:57 volumio volumio[10063]: at /volumio/app/plugins/music_service/mpd/index.js:2582:21
May 27 06:56:57 volumio volumio[10063]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3)
May 27 06:56:57 volumio volumio[10063]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12)
May 27 06:56:57 volumio volumio[10063]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12)
May 27 06:56:57 volumio volumio[10063]: at Socket.emit (node:events:514:28)
May 27 06:56:57 volumio volumio[10063]: at addChunk (node:internal/streams/readable:343:12)
May 27 06:56:57 volumio volumio[10063]: at readableAddChunk (node:internal/streams/readable:312:11)
May 27 06:56:57 volumio volumio[10063]: at Readable.push (node:internal/streams/readable:253:10)
May 27 06:56:57 volumio volumio[10063]: at Pipe.onStreamRead (node:internal/stream_base_commons:190:23)
May 27 06:56:57 volumio volumio[10063]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 27 06:56:57 volumio sudo[10419]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-05-27 06:55'
May 27 06:56:57 volumio sudo[10419]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Debian GNU/Linux 12 (bookworm)"
NAME="Debian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"
VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b"
VOLUMIO_ARCH="x64"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue Mar 24 17:45:45 UTC 2026"
VOLUMIO_VERSION="4.119"
VOLUMIO_HARDWARE="x86_amd64"
VOLUMIO_DEVICENAME="x86_64"
VOLUMIO_HASH="6bf7cd61fe53483b72878254df87f1c0"