-- Logs begin at Mon 2025-05-19 15:22:50 JST, end at Mon 2025-05-19 15:35:09 JST. -- May 19 15:34:22 volumio systemd-timedated[951]: Changed local time to Mon May 19 15:34:22 2025 May 19 15:34:22 volumio sudo[941]: pam_unix(sudo:session): session closed for user root May 19 15:34:22 volumio volumio-time-update[540]: volumio-time-update-util: System time updated successfully. May 19 15:34:22 volumio systemd[1]: Started Volumio Time Update Utility. May 19 15:34:22 volumio volumio[803]: info: ------------------------------------------- May 19 15:34:22 volumio volumio[803]: info: ----- Volumio3 ---- May 19 15:34:22 volumio volumio[803]: info: ------------------------------------------- May 19 15:34:22 volumio volumio[803]: info: ----- System startup ---- May 19 15:34:22 volumio volumio[803]: info: ------------------------------------------- May 19 15:34:22 volumio ntpd[907]: Soliciting pool server 172.237.12.44 May 19 15:34:22 volumio ntpd[907]: Soliciting pool server 129.250.35.251 May 19 15:34:23 volumio ntpd[907]: Soliciting pool server 133.130.121.141 May 19 15:34:23 volumio ntpd[907]: Soliciting pool server 103.131.151.20 May 19 15:34:23 volumio nmbd[745]: [2025/05/19 15:34:23.708908, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 19 15:34:23 volumio nmbd[745]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections May 19 15:34:23 volumio systemd[1]: Started Samba NMB Daemon. May 19 15:34:23 volumio systemd[1]: Starting Samba Winbind Daemon... May 19 15:34:23 volumio ntpd[907]: Soliciting pool server 162.159.200.123 May 19 15:34:23 volumio volumio-remote-updater[569]: [2025-05-19 15:34:23] [connect] Successful connection May 19 15:34:24 volumio volumio[803]: info: MYVOLUMIO Environment detected May 19 15:34:24 volumio winbindd[952]: [2025/05/19 15:34:24.325966, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) May 19 15:34:24 volumio winbindd[952]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 May 19 15:34:24 volumio winbindd[952]: [2025/05/19 15:34:24.360346, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 19 15:34:24 volumio winbindd[952]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections May 19 15:34:24 volumio systemd[1]: Started Samba Winbind Daemon. May 19 15:34:24 volumio systemd[1]: Starting Samba SMB Daemon... May 19 15:34:24 volumio ntpd[907]: Soliciting pool server 23.81.40.154 May 19 15:34:24 volumio ntpd[907]: Soliciting pool server 129.250.35.250 May 19 15:34:24 volumio ntpd[907]: Soliciting pool server 122.215.240.51 May 19 15:34:24 volumio volumio[803]: info: Plugin folders cleanup May 19 15:34:24 volumio volumio[803]: info: Scanning into folder /volumio/app/plugins/ May 19 15:34:24 volumio volumio[803]: info: Scanning category audio_interface May 19 15:34:24 volumio volumio[803]: info: Scanning category miscellanea May 19 15:34:24 volumio volumio[803]: info: Scanning category music_service May 19 15:34:24 volumio volumio[803]: info: Scanning category plugins.json May 19 15:34:24 volumio volumio[803]: info: Scanning category system_controller May 19 15:34:24 volumio volumio[803]: info: Scanning category user_interface May 19 15:34:24 volumio volumio[803]: info: Scanning into folder /data/plugins/ May 19 15:34:24 volumio volumio[803]: info: Plugin folders cleanup completed May 19 15:34:24 volumio volumio[803]: info: ------------------------------------------- May 19 15:34:24 volumio volumio[803]: info: ----- Core plugins startup ---- May 19 15:34:24 volumio volumio[803]: info: ------------------------------------------- May 19 15:34:24 volumio volumio[803]: info: Loading plugins from folder /volumio/app/plugins/ May 19 15:34:24 volumio volumio[803]: info: Adding plugin bluetooth to MyMusic Plugins May 19 15:34:24 volumio volumio[803]: info: Adding plugin multiroom to MyMusic Plugins May 19 15:34:24 volumio volumio[803]: info: Adding plugin upnp to MyMusic Plugins May 19 15:34:24 volumio volumio[803]: info: Adding plugin metavolumio to MyMusic Plugins May 19 15:34:24 volumio volumio[803]: info: Adding plugin airplay_emulation to MyMusic Plugins May 19 15:34:24 volumio volumio[803]: info: Adding plugin cd_controller to MyMusic Plugins May 19 15:34:24 volumio volumio[803]: info: Adding plugin raat to MyMusic Plugins May 19 15:34:24 volumio volumio[803]: info: Adding plugin smart_inputs to MyMusic Plugins May 19 15:34:24 volumio volumio[803]: info: Adding plugin tidalconnect to MyMusic Plugins May 19 15:34:24 volumio volumio[803]: info: Adding plugin upnp_browser to MyMusic Plugins May 19 15:34:24 volumio volumio[803]: info: Loading plugins from folder /data/plugins/ May 19 15:34:24 volumio volumio[803]: info: Loading plugin "system"... May 19 15:34:24 volumio volumio[803]: info: Loading plugin "appearance"... May 19 15:34:25 volumio ntpd[907]: Soliciting pool server 162.159.200.1 May 19 15:34:25 volumio smbd[959]: [2025/05/19 15:34:25.350098, 0] ../lib/util/become_daemon.c:138(daemon_ready) May 19 15:34:25 volumio systemd[1]: Started Samba SMB Daemon. May 19 15:34:25 volumio smbd[959]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections May 19 15:34:25 volumio systemd[1]: Reached target Multi-User System. May 19 15:34:25 volumio systemd[1]: Reached target Graphical Interface. May 19 15:34:25 volumio systemd[1]: Starting Update UTMP about System Runlevel Changes... May 19 15:34:25 volumio systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. May 19 15:34:25 volumio systemd[1]: Started Update UTMP about System Runlevel Changes. May 19 15:34:25 volumio systemd[1]: Startup finished in 6.072s (kernel) + 20.073s (userspace) = 26.146s. May 19 15:34:25 volumio ntpd[907]: Soliciting pool server 139.162.81.45 May 19 15:34:25 volumio ntpd[907]: Soliciting pool server 45.76.211.39 May 19 15:34:25 volumio ntpd[907]: Soliciting pool server 160.16.113.133 May 19 15:34:26 volumio ntpd[907]: Soliciting pool server 45.77.20.103 May 19 15:34:26 volumio ntpd[907]: Soliciting pool server 35.72.105.27 May 19 15:34:27 volumio ntpd[907]: Soliciting pool server 2001:19f0:7001:5fde:5400:4ff:fe34:27f0 May 19 15:34:27 volumio volumio[803]: info: Loading plugin "network"... May 19 15:34:27 volumio volumio[803]: info: Refreshing Cached IP Addresses May 19 15:34:27 volumio sudo[972]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 19 15:34:27 volumio sudo[972]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:27 volumio sudo[972]: pam_unix(sudo:session): session closed for user root May 19 15:34:27 volumio volumio[803]: info: Loading plugin "services"... May 19 15:34:27 volumio sudo[974]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 19 15:34:27 volumio sudo[974]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:27 volumio volumio[803]: info: Loading plugin "alsa_controller"... May 19 15:34:27 volumio sudo[974]: pam_unix(sudo:session): session closed for user root May 19 15:34:27 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 19 15:34:27 volumio volumio[803]: info: Loading plugin "wizard"... May 19 15:34:27 volumio volumio[803]: info: Loading plugin "networkfs"... May 19 15:34:28 volumio volumio[803]: info: Starting Udev Watcher for removable devices May 19 15:34:28 volumio sudo[995]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o username=pnp666,password=Masa!0701,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.1.155/MUSIC/vtuber /mnt/NAS/Synology May 19 15:34:28 volumio sudo[995]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:28 volumio volumio[803]: info: Ignoring mount for partition: boot May 19 15:34:28 volumio volumio[803]: info: Ignoring mount for partition: volumio May 19 15:34:28 volumio volumio[803]: info: Ignoring mount for partition: volumio_data May 19 15:34:28 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 19 15:34:28 volumio volumio[803]: info: Loading plugin "volumio_command_line_client"... May 19 15:34:28 volumio volumio[803]: info: Loading plugin "upnp"... May 19 15:34:28 volumio volumio[803]: info: [1747636468120] Starting Upmpd Daemon May 19 15:34:28 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 19 15:34:28 volumio volumio[803]: info: Loading plugin "my_music"... May 19 15:34:28 volumio kernel: FS-Cache: Loaded May 19 15:34:28 volumio volumio[803]: info: Loading plugin "mpd"... May 19 15:34:28 volumio kernel: FS-Cache: Netfs 'cifs' registered for caching May 19 15:34:28 volumio kernel: Key type cifs.spnego registered May 19 15:34:28 volumio kernel: Key type cifs.idmap registered May 19 15:34:28 volumio kernel: CIFS: Attempting to mount //192.168.1.155/MUSIC/vtuber May 19 15:34:28 volumio kernel: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount. May 19 15:34:28 volumio sudo[995]: pam_unix(sudo:session): session closed for user root May 19 15:34:28 volumio volumio[803]: info: Loading plugin "upnp_browser"... May 19 15:34:30 volumio ntpd[907]: receive: Unexpected origin timestamp 0xebd54f75.8aad3d53 does not match aorg 0000000000.00000000 from server@139.162.81.45 xmt 0xebd54f76.a31dd68c May 19 15:34:30 volumio volumio[803]: info: Loading plugin "bluetooth"... May 19 15:34:30 volumio ntpd[907]: receive: Unexpected origin timestamp 0xebd54f75.8ab52254 does not match aorg 0000000000.00000000 from server@103.131.151.20 xmt 0xebd54f76.ccd7be98 May 19 15:34:31 volumio volumio[803]: info: [1747636471151] Starting BluetoothController May 19 15:34:31 volumio volumio[803]: info: Loading plugin "alarm-clock"... May 19 15:34:31 volumio volumio[803]: info: Loading plugin "manifestui"... May 19 15:34:32 volumio volumio[803]: info: Loading plugin "metavolumio"... May 19 15:34:34 volumio volumio[803]: info: Loading plugin "airplay_emulation"... May 19 15:34:34 volumio volumio[803]: info: Starting Shairport Sync May 19 15:34:34 volumio volumio[803]: info: Loading plugin "cd_controller"... May 19 15:34:35 volumio volumio[803]: info: Loading plugin "last_100"... May 19 15:34:35 volumio volumio[803]: info: Loading plugin "raat"... May 19 15:34:35 volumio volumio[803]: info: RAAT Plugin loaded May 19 15:34:35 volumio volumio[803]: info: Adding restartRAATSocket REST API Endpoint May 19 15:34:35 volumio volumio[803]: info: Adding restartRAATSocket REST Endpoint for plugin: music_service/raat May 19 15:34:35 volumio volumio[803]: info: Loading plugin "streaming_services"... May 19 15:34:38 volumio volumio[803]: info: Starting Streaming Service Transparent Proxy May 19 15:34:38 volumio volumio[803]: info: Loading plugin "tidalconnect"... May 19 15:34:38 volumio volumio[803]: info: Loading plugin "webradio"... May 19 15:34:38 volumio volumio[803]: info: Loading plugin "i2s_dacs"... May 19 15:34:38 volumio volumio[803]: info: I2S DAC not set, start Auto-detection May 19 15:34:38 volumio volumio[803]: info: Loading plugin "volumiodiscovery"... May 19 15:34:39 volumio volumio[803]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 19 15:34:39 volumio node[803]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 19 15:34:39 volumio node[803]: *** WARNING *** Please fix your application to use the native API of Avahi! May 19 15:34:39 volumio volumio[803]: *** WARNING *** Please fix your application to use the native API of Avahi! May 19 15:34:39 volumio volumio[803]: *** WARNING *** For more information see May 19 15:34:39 volumio volumio[803]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 19 15:34:39 volumio volumio[803]: *** WARNING *** Please fix your application to use the native API of Avahi! May 19 15:34:39 volumio volumio[803]: *** WARNING *** For more information see May 19 15:34:39 volumio node[803]: *** WARNING *** For more information see May 19 15:34:39 volumio node[803]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 19 15:34:39 volumio node[803]: *** WARNING *** Please fix your application to use the native API of Avahi! May 19 15:34:39 volumio node[803]: *** WARNING *** For more information see May 19 15:34:39 volumio volumio[803]: info: Applying required configuration parameters for plugin volumiodiscovery May 19 15:34:39 volumio volumio[803]: info: Discovery: Started advertising with name: volumio May 19 15:34:39 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 19 15:34:39 volumio volumio[803]: info: Loading plugin "multiroom"... May 19 15:34:39 volumio volumio-remote-updater[569]: [2025-05-19 15:34:39] [connect] Successful connection May 19 15:34:40 volumio systemd[1]: systemd-fsckd.service: Succeeded. May 19 15:34:40 volumio volumio[803]: STREAMING PROXY: Starting server on port 3245 May 19 15:34:40 volumio volumio[803]: Node JS runtime: 14 May 19 15:34:42 volumio volumio[803]: info: Applying required configuration parameters for plugin multiroom May 19 15:34:42 volumio sudo[1049]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom May 19 15:34:42 volumio sudo[1049]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:42 volumio sudo[1049]: pam_unix(sudo:session): session closed for user root May 19 15:34:42 volumio volumio[803]: info: MRS: MultiRoom plugin initialized May 19 15:34:42 volumio volumio[803]: info: MRS: STOPPING SNAPCLIENT May 19 15:34:42 volumio volumio[803]: info: MRS: Snap server stop May 19 15:34:42 volumio volumio[803]: info: MRS: STOPPING volumioStreaming May 19 15:34:42 volumio sudo[1065]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient May 19 15:34:42 volumio sudo[1065]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:42 volumio sudo[1067]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver May 19 15:34:42 volumio sudo[1067]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:42 volumio sudo[1065]: pam_unix(sudo:session): session closed for user root May 19 15:34:42 volumio volumio[803]: info: Loading plugin "outputs"... May 19 15:34:42 volumio sudo[1070]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming May 19 15:34:42 volumio sudo[1070]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:42 volumio volumio[803]: info: Loading plugin "albumart"... May 19 15:34:42 volumio sudo[1073]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* May 19 15:34:42 volumio sudo[1073]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:42 volumio sudo[1067]: pam_unix(sudo:session): session closed for user root May 19 15:34:42 volumio sudo[1073]: pam_unix(sudo:session): session closed for user root May 19 15:34:42 volumio volumio[803]: info: Plugin example_plugin is not enabled May 19 15:34:42 volumio sudo[1070]: pam_unix(sudo:session): session closed for user root May 19 15:34:42 volumio volumio[803]: info: Loading plugin "hi_res_audio"... May 19 15:34:43 volumio volumio[803]: Forking 3 albumart workers May 19 15:34:45 volumio volumio[803]: Starting albumart workers May 19 15:34:45 volumio volumio[803]: Starting albumart workers May 19 15:34:45 volumio volumio[803]: Starting albumart workers May 19 15:34:46 volumio volumio[803]: info: Applying required configuration parameters for plugin hi_res_audio May 19 15:34:46 volumio volumio[803]: info: Loading plugin "inputs"... May 19 15:34:47 volumio volumio[803]: info: Loading plugin "qobuz"... May 19 15:34:50 volumio volumio[803]: info: Loading plugin "smart_inputs"... May 19 15:34:51 volumio volumio[803]: info: Loading plugin "tidal"... May 19 15:34:53 volumio systemd[1]: systemd-timedated.service: Succeeded. May 19 15:34:53 volumio volumio[803]: info: Loading plugin "oem_helper"... May 19 15:34:54 volumio volumio-remote-updater[569]: [2025-05-19 15:34:54] [connect] Successful connection May 19 15:34:55 volumio volumio[803]: info: Applying required configuration parameters for plugin oem_helper May 19 15:34:55 volumio volumio[803]: info: Loading plugin "smslcontrol"... May 19 15:34:55 volumio kernel: gpio gpiochip0: Persistence not supported for GPIO 5 May 19 15:34:55 volumio volumio[803]: info: Adding this device properties May 19 15:34:55 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , setThisDeviceVolumioProperties May 19 15:34:55 volumio volumio[803]: info: Setting Additional Device Volumio Properties: [object Object] May 19 15:34:55 volumio volumio[803]: info: Loading plugin "updater_comm"... May 19 15:34:56 volumio volumio[803]: info: Plugin mpdemulation is not enabled May 19 15:34:56 volumio volumio[803]: info: Loading plugin "rest_api"... May 19 15:34:56 volumio volumio[803]: info: Loading plugin "websocket"... May 19 15:34:56 volumio volumio[803]: info: Starting Socket.io Server version 2.3.0 May 19 15:34:56 volumio volumio[803]: info: Loading i18n strings for locale ja May 19 15:34:56 volumio volumio[803]: Updating browse sources language May 19 15:34:56 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 19 15:34:56 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 19 15:34:56 volumio volumio[803]: info: CoreCommandRouter::initPlayerControls May 19 15:34:56 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:34:56 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:34:56 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:34:56 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:34:56 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:34:56 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:34:56 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:34:56 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:34:56 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 19 15:34:56 volumio volumio[803]: Express server listening on port 3000 May 19 15:34:56 volumio volumio[803]: [Metrics] WebUI: 35s 151.94ms May 19 15:34:57 volumio volumio[803]: info: CoreStateMachine::resetVolumioState May 19 15:34:57 volumio volumio[803]: info: CoreStateMachine::getcurrentVolume May 19 15:34:57 volumio volumio[803]: info: CoreCommandRouter::volumioRetrievevolume May 19 15:34:57 volumio volumio[803]: info: CoreStateMachine::pushState May 19 15:34:57 volumio volumio[803]: info: CorePlayQueue::getTrack 0 May 19 15:34:57 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 19 15:34:57 volumio volumio[803]: info: CoreCommandRouter::volumioPushState May 19 15:34:57 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 19 15:34:57 volumio sudo[1162]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 19 15:34:57 volumio sudo[1162]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:57 volumio sudo[1162]: pam_unix(sudo:session): session closed for user root May 19 15:34:57 volumio sudo[1164]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 19 15:34:57 volumio sudo[1164]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:57 volumio volumio[803]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' May 19 15:34:57 volumio volumio[803]: info: Completed loading Core Plugins May 19 15:34:57 volumio sudo[1164]: pam_unix(sudo:session): session closed for user root May 19 15:34:57 volumio volumio[803]: info: Preparing to generate the ALSA configuration file May 19 15:34:57 volumio volumio[803]: info: Volumio Network Manager: Network status updated: 1 May 19 15:34:57 volumio volumio[803]: info: MRS: Removed streaming files May 19 15:34:57 volumio volumio[803]: info: MRS: volumioStreaming STOPPED May 19 15:34:57 volumio volumio[803]: info: MRS: SNAPSERVER STOPPED May 19 15:34:57 volumio volumio[803]: info: MRS: SNAPCLIENT STOPPED May 19 15:34:57 volumio volumio[803]: info: Cannot read proc/cpuinfo: Error: Command failed: cat /proc/cpuinfo | grep Revision May 19 15:34:57 volumio volumio[803]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf May 19 15:34:57 volumio volumio[803]: info: Reading ALSA contributions from plugins. May 19 15:34:57 volumio volumio-remote-updater[569]: [2025-05-19 15:34:57] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1747636494 101 May 19 15:34:57 volumio volumio[803]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 1 May 19 15:34:57 volumio volumio[803]: info: Reloading queue from file May 19 15:34:57 volumio volumio[803]: info: CoreStateMachine::setRepeat null single undefined May 19 15:34:57 volumio volumio[803]: info: CoreStateMachine::pushState May 19 15:34:57 volumio volumio[803]: info: CorePlayQueue::getTrack 0 May 19 15:34:57 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 19 15:34:57 volumio volumio[803]: info: CoreCommandRouter::volumioPushState May 19 15:34:57 volumio volumio[803]: info: CoreStateMachine::setRandom null May 19 15:34:57 volumio volumio[803]: info: CoreStateMachine::pushState May 19 15:34:57 volumio volumio[803]: info: CorePlayQueue::getTrack 0 May 19 15:34:57 volumio volumio[803]: info: CoreCommandRouter::volumioPushState May 19 15:34:57 volumio volumio[803]: info: Setting Device type: NanoPi NEO 3 May 19 15:34:57 volumio volumio[803]: info: Asound.conf file unchanged, so no further update is needed May 19 15:34:57 volumio volumio[803]: info: Output device has changed, restarting MPD May 19 15:34:57 volumio sudo[1173]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 19 15:34:57 volumio sudo[1173]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:57 volumio systemd[1]: Started UPnP Renderer front-end to MPD. May 19 15:34:57 volumio sudo[1176]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 19 15:34:58 volumio sudo[1176]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:58 volumio volumio[803]: info: Output device has changed, restarting Shairport Sync May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 19 15:34:58 volumio sudo[1176]: pam_unix(sudo:session): session closed for user root May 19 15:34:58 volumio sudo[1173]: pam_unix(sudo:session): session closed for user root May 19 15:34:58 volumio sudo[1180]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 19 15:34:58 volumio sudo[1180]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:58 volumio systemd[1]: Stopping Music Player Daemon... May 19 15:34:58 volumio volumio[803]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 19 15:34:58 volumio volumio[803]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:34:58 volumio volumio[803]: info: ___________ START PLUGINS ___________ May 19 15:34:58 volumio volumio[803]: info: ControllerMpd::onStart: Initializing MPD May 19 15:34:58 volumio volumio[803]: info: Creating MPD Configuration file May 19 15:34:58 volumio sudo[1188]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 19 15:34:58 volumio sudo[1188]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 19 15:34:58 volumio volumio[803]: info: [1747636498320] CoreMusicLibrary::Adding element DLNAサーバー May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 19 15:34:58 volumio sudo[1188]: pam_unix(sudo:session): session closed for user root May 19 15:34:58 volumio sudo[1190]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 19 15:34:58 volumio sudo[1190]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 19 15:34:58 volumio volumio[803]: info: Adding METAVOLUMIO REST API Endpoints May 19 15:34:58 volumio volumio[803]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio May 19 15:34:58 volumio volumio[803]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio May 19 15:34:58 volumio volumio[803]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio May 19 15:34:58 volumio volumio[803]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 19 15:34:58 volumio systemd[1]: mpd.service: Succeeded. May 19 15:34:58 volumio systemd[1]: Stopped Music Player Daemon. May 19 15:34:58 volumio sudo[1194]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name volumio May 19 15:34:58 volumio sudo[1194]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:58 volumio systemd[1]: Starting Music Player Daemon... May 19 15:34:58 volumio sudo[1194]: pam_unix(sudo:session): session closed for user root May 19 15:34:58 volumio volumio[803]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 19 15:34:58 volumio volumio[803]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 19 15:34:58 volumio volumio[803]: info: Preparing CD Folders May 19 15:34:58 volumio volumio[803]: info: Adding CD REST API Endpoints May 19 15:34:58 volumio volumio[803]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller May 19 15:34:58 volumio volumio[803]: info: Starting UDEV Watcher for CD May 19 15:34:58 volumio volumio[803]: info: Detecting CD presence with UDEV May 19 15:34:58 volumio sudo[1196]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices May 19 15:34:58 volumio sudo[1196]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:58 volumio sudo[1196]: pam_unix(sudo:session): session closed for user root May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 19 15:34:58 volumio volumio[803]: info: [1747636498724] CoreMusicLibrary::Adding element Last_100 May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 19 15:34:58 volumio volumio[803]: info: Starting RAAT Plugin May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , addAdditionalUISections May 19 15:34:58 volumio volumio[803]: info: Additional UI Settings Added for plugin music_service/raat May 19 15:34:58 volumio volumio[803]: info: Registering DSP Elements listener and retrieving current ones May 19 15:34:58 volumio volumio[803]: info: Additional DSP elements updated May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:34:58 volumio volumio[803]: info: Updating RAAT Signal Path May 19 15:34:58 volumio volumio[803]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined May 19 15:34:58 volumio volumio[803]: info: Streaming services startup May 19 15:34:58 volumio volumio[803]: info: Starting Streaming Daemon May 19 15:34:58 volumio sudo[1208]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service May 19 15:34:58 volumio sudo[1208]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:58 volumio sudo[1208]: pam_unix(sudo:session): session closed for user root May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 19 15:34:58 volumio volumio[803]: info: [1747636498981] CoreMusicLibrary::Adding element Webradio May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 19 15:34:58 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 19 15:34:59 volumio volumio[803]: info: Initializing BBC Radios May 19 15:34:59 volumio sudo[1215]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service May 19 15:34:59 volumio sudo[1215]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:34:59 volumio sudo[1215]: pam_unix(sudo:session): session closed for user root May 19 15:34:59 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 19 15:34:59 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 19 15:34:59 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus May 19 15:34:59 volumio volumio[803]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration May 19 15:34:59 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:34:59 volumio volumio[803]: error: Hi Res Audio Failed Login: Missing Login Data May 19 15:34:59 volumio volumio[803]: info: Adding HIGHRESAUDIO REST API Endpoints May 19 15:34:59 volumio volumio[803]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio May 19 15:34:59 volumio volumio[803]: info: Initializing Serial Communication on port /dev/ttyS1 May 19 15:34:59 volumio volumio[803]: info: Touch Event Listener Process Starting May 19 15:34:59 volumio volumio[803]: info: Refreshing QOBUZ token May 19 15:34:59 volumio sudo[1246]: pam_unix(sudo:auth): conversation failed May 19 15:34:59 volumio sudo[1246]: pam_unix(sudo:auth): auth could not identify password for [volumio] May 19 15:34:59 volumio volumio[803]: info: Adding inputs REST Endpoints May 19 15:34:59 volumio volumio[803]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs May 19 15:34:59 volumio volumio[803]: info: Scanning Audio Inputs May 19 15:34:59 volumio volumio[803]: info: Checking against Known Cards name May 19 15:34:59 volumio volumio[803]: info: Adding Server instance for streaming May 19 15:34:59 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 19 15:34:59 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 19 15:34:59 volumio volumio[803]: info: Initializing GPIOs May 19 15:34:59 volumio kernel: gpio gpiochip3: Persistence not supported for GPIO 1 May 19 15:34:59 volumio kernel: gpio gpiochip2: Persistence not supported for GPIO 15 May 19 15:34:59 volumio kernel: gpio gpiochip3: Persistence not supported for GPIO 0 May 19 15:34:59 volumio kernel: gpio gpiochip2: Persistence not supported for GPIO 2 May 19 15:34:59 volumio volumio[803]: info: Starting Button Listener May 19 15:34:59 volumio volumio[803]: info: Turning off Green LED May 19 15:34:59 volumio volumio[803]: info: Tuning on Blue LED May 19 15:34:59 volumio volumio[803]: info: Signaling System Ready May 19 15:34:59 volumio volumio[803]: info: Volumio Calling Home May 19 15:35:00 volumio volumio[803]: (node:803) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. May 19 15:35:00 volumio volumio[803]: (Use `node --trace-deprecation ...` to show where the warning was created) May 19 15:35:00 volumio volumio[803]: info: Stopping AccessToken refresher cron May 19 15:35:00 volumio volumio[803]: info: AccessToken refresher cron started May 19 15:35:00 volumio volumio[803]: info: Adding TIDAL REST API Endpoints May 19 15:35:00 volumio volumio[803]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal May 19 15:35:00 volumio volumio[803]: info: Serial port opened successfully May 19 15:35:00 volumio volumio[803]: info: Sending serial start messages May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:00 volumio volumio[803]: info: Reporting MCU Network Status: 1 May 19 15:35:00 volumio volumio[803]: info: Touch Event Listener Process Closed May 19 15:35:00 volumio volumio[803]: error: Cannot start Volumio Streaming Daemon May 19 15:35:00 volumio volumio[803]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service May 19 15:35:00 volumio volumio[803]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. May 19 15:35:00 volumio volumio[803]: info: RAAT Albumart path created successfully May 19 15:35:00 volumio volumio[803]: error: Cannot set new Bluetooth Name : Error: Command failed: /usr/bin/sudo /bin/hciconfig hci0 name 'volumio' May 19 15:35:00 volumio volumio[803]: Can't get device info: No such device May 19 15:35:00 volumio volumio[803]: info: MPD Permissions set May 19 15:35:00 volumio volumio[803]: info: MPD Permissions set May 19 15:35:00 volumio volumio[803]: info: Upmpdcli Daemon Started May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride May 19 15:35:00 volumio volumio[803]: info: Setting Device Volume Override May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 19 15:35:00 volumio volumio[803]: info: Updating Volume Controller Parameters: Device: 5 Name: Singxer DAC USB Audio Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 19 15:35:00 volumio volumio[803]: info: Disabling external Volume Control May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:00 volumio volumio[803]: info: CoreStateMachine::pushState May 19 15:35:00 volumio volumio[803]: info: CorePlayQueue::getTrack 0 May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::volumioPushState May 19 15:35:00 volumio volumio[803]: error: Serial API: Failed to decode command: 100, message: undefined May 19 15:35:00 volumio volumio[803]: error: Serial API: Failed to decode command: MAXVOL, message: May 19 15:35:00 volumio volumio[803]: error: Serial API: Failed to decode command: 100, message: undefined May 19 15:35:00 volumio volumio[803]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff May 19 15:35:00 volumio volumio[803]: info: CoreStateMachine::pushState May 19 15:35:00 volumio volumio[803]: info: CorePlayQueue::getTrack 0 May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::volumioPushState May 19 15:35:00 volumio volumio[803]: info: CoreStateMachine::pushState May 19 15:35:00 volumio volumio[803]: info: CorePlayQueue::getTrack 0 May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::volumioPushState May 19 15:35:00 volumio volumio[803]: error: Serial API: Failed to decode command: 100, message: undefined May 19 15:35:00 volumio volumio[803]: error: Serial API: Failed to decode command: MAXVOL, message: May 19 15:35:00 volumio volumio[803]: error: Serial API: Failed to decode command: 100, message: undefined May 19 15:35:00 volumio volumio[803]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff May 19 15:35:00 volumio volumio[803]: info: CoreStateMachine::pushState May 19 15:35:00 volumio volumio[803]: info: CorePlayQueue::getTrack 0 May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::volumioPushState May 19 15:35:00 volumio volumio[803]: error: Serial API: Failed to decode command: 100, message: undefined May 19 15:35:00 volumio volumio[803]: error: Serial API: Failed to decode command: MAXVOL, message: May 19 15:35:00 volumio volumio[803]: error: Serial API: Failed to decode command: 100, message: undefined May 19 15:35:00 volumio volumio[803]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff May 19 15:35:00 volumio volumio[803]: error: Serial API: Failed to decode command: 1, message: undefined May 19 15:35:00 volumio volumio[803]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 19 15:35:00 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 19 15:35:01 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:01 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:01 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:01 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:01 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:01 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:01 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:01 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:01 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 19 15:35:01 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber May 19 15:35:01 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 19 15:35:01 volumio volumio[803]: info: CoreStateMachine::pushState May 19 15:35:01 volumio volumio[803]: info: CorePlayQueue::getTrack 0 May 19 15:35:01 volumio volumio[803]: info: CoreCommandRouter::volumioPushState May 19 15:35:01 volumio volumio[803]: error: Serial API: Failed to decode command: 100, message: undefined May 19 15:35:01 volumio volumio[803]: error: Serial API: Failed to decode command: MAXVOL, message: May 19 15:35:01 volumio volumio[803]: error: Serial API: Failed to decode command: 100, message: undefined May 19 15:35:01 volumio volumio[803]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff May 19 15:35:01 volumio volumio[803]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 May 19 15:35:01 volumio volumio[803]: info: Volumio called home May 19 15:35:01 volumio volumio[803]: info: Starting Shairport Sync May 19 15:35:01 volumio sudo[1293]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service May 19 15:35:01 volumio sudo[1293]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:35:01 volumio volumio[803]: info: Starting Shairport Sync May 19 15:35:01 volumio sudo[1296]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 19 15:35:01 volumio volumio[803]: info: Starting Shairport Sync May 19 15:35:01 volumio sudo[1296]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:35:01 volumio systemd[1]: Started Volumio Bluetooth Module. May 19 15:35:01 volumio sudo[1293]: pam_unix(sudo:session): session closed for user root May 19 15:35:01 volumio sudo[1299]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 19 15:35:01 volumio sudo[1299]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:35:01 volumio volumio[803]: info: CoreStateMachine::pushState May 19 15:35:01 volumio volumio[803]: info: CorePlayQueue::getTrack 0 May 19 15:35:01 volumio volumio[803]: info: CoreCommandRouter::volumioPushState May 19 15:35:01 volumio volumio[803]: error: Serial API: Failed to decode command: 100, message: undefined May 19 15:35:01 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 19 15:35:01 volumio volumio[803]: error: Serial API: Failed to decode command: MAXVOL, message: May 19 15:35:01 volumio volumio[803]: error: Serial API: Failed to decode command: 100, message: undefined May 19 15:35:01 volumio systemd[1]: shairport-sync.service: Succeeded. May 19 15:35:01 volumio volumio[803]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff May 19 15:35:01 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 19 15:35:01 volumio volumio[803]: info: CoreStateMachine::pushState May 19 15:35:01 volumio volumio[803]: info: CorePlayQueue::getTrack 0 May 19 15:35:01 volumio sudo[1304]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 19 15:35:01 volumio volumio[803]: info: CoreCommandRouter::volumioPushState May 19 15:35:01 volumio sudo[1304]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:35:01 volumio sudo[1302]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* May 19 15:35:01 volumio sudo[1302]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:35:01 volumio volumio[803]: error: Serial API: Failed to decode command: 100, message: undefined May 19 15:35:01 volumio volumio[803]: error: Serial API: Failed to decode command: MAXVOL, message: May 19 15:35:01 volumio volumio[803]: error: Serial API: Failed to decode command: 100, message: undefined May 19 15:35:01 volumio volumio[803]: info: MCU Signalled PowerOff Capabilities, enabling MCU Poweroff May 19 15:35:01 volumio volumiobt[1298]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory May 19 15:35:01 volumio sudo[1302]: pam_unix(sudo:session): session closed for user root May 19 15:35:01 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 19 15:35:01 volumio sudo[1296]: pam_unix(sudo:session): session closed for user root May 19 15:35:01 volumio sudo[1299]: pam_unix(sudo:session): session closed for user root May 19 15:35:02 volumio volumio[803]: info: Access Token successfully retrieved May 19 15:35:02 volumio volumio[803]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 19 15:35:02 volumio volumio[803]: info: [1747636502033] CoreMusicLibrary::Adding element QOBUZ May 19 15:35:02 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 19 15:35:02 volumio volumio[803]: Cannot find translation for source QOBUZ May 19 15:35:02 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 19 15:35:02 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 19 15:35:02 volumio systemd[1]: shairport-sync.service: Succeeded. May 19 15:35:02 volumio volumio[803]: info: Stopping AccessToken refresher cron for QOBUZ May 19 15:35:02 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 19 15:35:02 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 19 15:35:02 volumio sudo[1304]: pam_unix(sudo:session): session closed for user root May 19 15:35:02 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 19 15:35:02 volumio systemd[1]: mpd.service: Failed with result 'protocol'. May 19 15:35:02 volumio systemd[1]: Failed to start Music Player Daemon. May 19 15:35:02 volumio sudo[1190]: pam_unix(sudo:session): session closed for user root May 19 15:35:02 volumio volumio[803]: info: AccessToken refresher cron started for QOBUZ May 19 15:35:02 volumio volumio[803]: info: Adding QOBUZ REST API Endpoints May 19 15:35:02 volumio volumio[803]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz May 19 15:35:02 volumio sudo[1180]: pam_unix(sudo:session): session closed for user root May 19 15:35:02 volumio systemd[1]: Starting Music Player Daemon... May 19 15:35:02 volumio volumio[803]: info: CoreCommandRouter::volumioGetState May 19 15:35:02 volumio volumio[803]: info: CorePlayQueue::getTrack 0 May 19 15:35:02 volumio sudo[1314]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 19 15:35:02 volumio sudo[1314]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:35:02 volumio sudo[1314]: pam_unix(sudo:session): session closed for user root May 19 15:35:02 volumio volumio[803]: info: Shairport-Sync Started May 19 15:35:02 volumio volumio[803]: Error adding Membership: Error: addMembership EINVAL May 19 15:35:02 volumio volumio[803]: info: Shairport-Sync Started May 19 15:35:02 volumio volumio[803]: info: Shairport-Sync Started May 19 15:35:02 volumio volumio[803]: info: Cannot restart MPD: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service May 19 15:35:02 volumio volumio[803]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. May 19 15:35:02 volumio volumio[803]: See "systemctl status mpd.service" and "journalctl -xe" for details. May 19 15:35:02 volumio volumio[803]: error: Cannot start MPD on system Start: Error: Command failed: /usr/bin/sudo /bin/systemctl restart mpd.service May 19 15:35:02 volumio volumio[803]: Job for mpd.service failed because the service did not take the steps required by its unit configuration. May 19 15:35:02 volumio volumio[803]: See "systemctl status mpd.service" and "journalctl -xe" for details. May 19 15:35:02 volumio volumio[803]: info: TidalConnect service stoped! May 19 15:35:02 volumio volumio[803]: info: Volumio BT Module successfully started May 19 15:35:02 volumio volumio[803]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect May 19 15:35:02 volumio volumio[803]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect May 19 15:35:02 volumio sudo[1327]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service May 19 15:35:02 volumio sudo[1327]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:35:02 volumio systemd[1]: Started Volumio Tidal Connect Service. May 19 15:35:02 volumio sudo[1327]: pam_unix(sudo:session): session closed for user root May 19 15:35:02 volumio sudo[1332]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio May 19 15:35:02 volumio sudo[1332]: pam_unix(sudo:session): session opened for user root by (uid=0) May 19 15:35:03 volumio volumiobt[1298]: pulseaudio: no process found May 19 15:35:03 volumio sudo[1332]: pam_unix(sudo:session): session closed for user root May 19 15:35:03 volumio dbus-daemon[532]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.16' (uid=1000 pid=1336 comm="/usr/bin/pulseaudio --high-priority=true ") May 19 15:35:03 volumio systemd[1]: Starting RealtimeKit Scheduling Policy Service... May 19 15:35:03 volumio volumio[803]: ------------------------------------ BT MESSAGE: BT STATUS: running May 19 15:35:03 volumio dbus-daemon[532]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' May 19 15:35:03 volumio systemd[1]: Started RealtimeKit Scheduling Policy Service. May 19 15:35:03 volumio rtkit-daemon[1337]: Successfully called chroot. May 19 15:35:03 volumio rtkit-daemon[1337]: Successfully dropped privileges. May 19 15:35:03 volumio rtkit-daemon[1337]: Successfully limited resources. May 19 15:35:03 volumio rtkit-daemon[1337]: Running. May 19 15:35:03 volumio rtkit-daemon[1337]: Canary thread running. May 19 15:35:03 volumio rtkit-daemon[1337]: Watchdog thread running. May 19 15:35:03 volumio dbus-daemon[532]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.17' (uid=0 pid=1337 comm="/usr/lib/rtkit/rtkit-daemon ") May 19 15:35:03 volumio systemd[1]: Starting Authorization Manager... May 19 15:35:03 volumio volumio[803]: ------------------------------------ BT MESSAGE: BT STATUS: running May 19 15:35:03 volumio polkitd[1340]: started daemon version 0.105 using authority implementation `local' version `0.105' May 19 15:35:03 volumio dbus-daemon[532]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' May 19 15:35:03 volumio systemd[1]: Started Authorization Manager. May 19 15:35:03 volumio volumio[803]: info: Executing endpoint tc_getconfig May 19 15:35:03 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig May 19 15:35:03 volumio vtcs[1329]: STARTING TidalConnect services, version: 1.4.0.34 May 19 15:35:04 volumio vtcs[1329]: STARTED TidalConnect services. May 19 15:35:04 volumio volumio[803]: info: Executing endpoint tc_connect May 19 15:35:04 volumio volumio[803]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect May 19 15:35:04 volumio volumio[803]: info: Connecting to TidalConnect May 19 15:35:04 volumio volumio[803]: info: CoreCommandRouter::servicePushState May 19 15:35:04 volumio volumio[803]: info: CoreStateMachine::pushState May 19 15:35:04 volumio volumio[803]: info: CorePlayQueue::getTrack 0 May 19 15:35:04 volumio volumio[803]: info: CoreCommandRouter::volumioPushState May 19 15:35:04 volumio volumio[803]: info: CorePlayQueue::getTrack 0 May 19 15:35:04 volumio volumio[803]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received tidalconnect May 19 15:35:04 volumio volumio[803]: info: CoreCommandRouter::servicePushState May 19 15:35:04 volumio volumio[803]: info: CoreStateMachine::pushState May 19 15:35:04 volumio volumio[803]: info: CorePlayQueue::getTrack 0 May 19 15:35:04 volumio volumio[803]: info: CoreCommandRouter::volumioPushState May 19 15:35:04 volumio volumio[803]: info: CorePlayQueue::getTrack 0 May 19 15:35:04 volumio volumio[803]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current qobuz Received tidalconnect May 19 15:35:04 volumio volumio[803]: info: MRS: Getting audio outputs on start May 19 15:35:04 volumio volumio[803]: info: MRS: Requesting all other devices output May 19 15:35:04 volumio dbus-daemon[532]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.38' (uid=1000 pid=1336 comm="/usr/bin/pulseaudio --high-priority=true ") May 19 15:35:04 volumio systemd[1]: Starting Bluetooth service... May 19 15:35:04 volumio volumio[803]: ------------------------------------ BT MESSAGE: BT STATUS: running May 19 15:35:04 volumio pulseaudio[1336]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 May 19 15:35:04 volumio pulseaudio[1336]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 May 19 15:35:04 volumio volumiobt[1298]: Applying permissions May 19 15:35:04 volumio volumiobt[1298]: Setting BT discoverable and pairable May 19 15:35:04 volumio bluetoothd[1361]: Bluetooth daemon 5.50 May 19 15:35:04 volumio bluetoothd[1361]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf May 19 15:35:04 volumio dbus-daemon[532]: [system] Successfully activated service 'org.bluez' May 19 15:35:04 volumio systemd[1]: Started Bluetooth service. May 19 15:35:04 volumio bluetoothd[1361]: Starting SDP server May 19 15:35:04 volumio bluetoothd[1361]: Excluding (cli) sap May 19 15:35:04 volumio bluetoothd[1361]: kernel lacks bnep-protocol support May 19 15:35:04 volumio bluetoothd[1361]: System does not support network plugin May 19 15:35:04 volumio dbus-daemon[532]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.39' (uid=0 pid=1361 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ") May 19 15:35:04 volumio bluetoothd[1361]: Bluetooth management interface 1.14 initialized May 19 15:35:04 volumio volumiobt[1298]: [bluetooth]# -e power on May 19 15:35:04 volumio volumiobt[1298]: Invalid command in menu main: -e May 19 15:35:04 volumio volumiobt[1298]: May 19 15:35:04 volumio volumiobt[1298]: Use "help" for a list of available commands in a menu. May 19 15:35:04 volumio volumiobt[1298]: Use "menu " if you want to enter any submenu. May 19 15:35:04 volumio volumiobt[1298]: Use "back" if you want to return to menu main. May 19 15:35:04 volumio volumiobt[1298]: [bluetooth]# agent on May 19 15:35:04 volumio volumiobt[1298]: Failed to register agent object May 19 15:35:04 volumio volumiobt[1298]: [bluetooth]# discoverable on May 19 15:35:04 volumio volumiobt[1298]: No default controller available May 19 15:35:04 volumio volumiobt[1298]: [bluetooth]# pairable on May 19 15:35:04 volumio volumiobt[1298]: No default controller available May 19 15:35:04 volumio volumiobt[1298]: [bluetooth]# agent NoInputNoOutput May 19 15:35:04 volumio volumiobt[1298]: Failed to register agent object May 19 15:35:04 volumio volumiobt[1298]: [bluetooth]# default-agent May 19 15:35:04 volumio volumiobt[1298]: No agent is registered May 19 15:35:04 volumio volumiobt[1298]: [bluetooth]# quit May 19 15:35:04 volumio pulseaudio[1336]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files May 19 15:35:04 volumio volumiobt[1298]: [59B blob data] May 19 15:35:04 volumio systemd[1]: Starting Hostname Service... May 19 15:35:04 volumio volumio[803]: ------------------------------------ BT MESSAGE: BT STATUS: running May 19 15:35:04 volumio dbus-daemon[532]: [system] Successfully activated service 'org.freedesktop.hostname1' May 19 15:35:04 volumio systemd[1]: Started Hostname Service. May 19 15:35:05 volumio volumio[803]: info: TidalConnect service started! May 19 15:35:05 volumio volumio[803]: info: Completed starting Core Plugins May 19 15:35:05 volumio volumio[803]: info: ------------------------------------------- May 19 15:35:05 volumio volumio[803]: info: ----- MyVolumio plugins startup ---- May 19 15:35:05 volumio volumio[803]: info: ------------------------------------------- May 19 15:35:05 volumio volumio[803]: info: [MyVolumio PluginManager] Fetching plans data.... May 19 15:35:06 volumio mpd[1317]: May 19 15:35 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 19 15:35:06 volumio systemd[1]: Started Music Player Daemon. May 19 15:35:06 volumio volumio[803]: Upnp client error: Error: This socket has been ended by the other party May 19 15:35:06 volumio mpd_monitor.sh[556]: MPD restarted due to no mpc output. May 19 15:35:07 volumio volumio[803]: error: MPD error: The expression evaluated to a falsy value: May 19 15:35:07 volumio volumio[803]: assert.ok(self.idling) May 19 15:35:07 volumio volumio[803]: error: The expression evaluated to a falsy value: May 19 15:35:07 volumio volumio[803]: assert.ok(self.idling) May 19 15:35:07 volumio volumio[803]: Upnp client error: Error: This socket has been ended by the other party May 19 15:35:07 volumio volumio[803]: error: updateQueue error: null May 19 15:35:08 volumio volumio[803]: info: Discovery: adding 1640aa27-d76a-4d83-9b88-3fe982da3ff1 May 19 15:35:08 volumio volumio[803]: info: Discovery: Found device volumio May 19 15:35:08 volumio volumio[803]: info: CoreCommandRouter::volumioGetState May 19 15:35:08 volumio volumio[803]: info: CorePlayQueue::getTrack 0 May 19 15:35:08 volumio volumio[803]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 19 15:35:08 volumio volumio[803]: Error: The value NaN is not a number May 19 15:35:08 volumio volumio[803]: at Config.forceToType (/volumio/node_modules/v-conf/index.js:322:20) May 19 15:35:08 volumio volumio[803]: at Config.set (/volumio/node_modules/v-conf/index.js:153:25) May 19 15:35:08 volumio volumio[803]: at ControllerVolumioDiscovery.updateMultiroomDevice (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:323:25) May 19 15:35:08 volumio volumio[803]: at ControllerVolumioDiscovery.connectToRemoteVolumio (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:273:10) May 19 15:35:08 volumio volumio[803]: at Browser. (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:192:12) May 19 15:35:08 volumio volumio[803]: at Browser.emit (events.js:400:28) May 19 15:35:08 volumio volumio[803]: at on_resolver_done (/volumio/node_modules/mdns/lib/browser.js:31:14) May 19 15:35:08 volumio volumio[803]: at next (/volumio/node_modules/mdns/lib/browser.js:106:7) May 19 15:35:08 volumio volumio[803]: at Array.makeAddressesUnique (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:177:5) May 19 15:35:08 volumio volumio[803]: at next (/volumio/node_modules/mdns/lib/browser.js:109:21) May 19 15:35:08 volumio volumio[803]: at /volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:160:11 May 19 15:35:08 volumio volumio[803]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:108:7) May 19 15:35:08 volumio volumio[803]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) May 19 15:35:08 volumio volumio[803]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 19 15:35:08 volumio volumio[1178]: Generating RSA private key, 4096 bit long modulus (2 primes) May 19 15:35:09 volumio sudo[1397]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-19 15:34 May 19 15:35:09 volumio sudo[1397]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="cc0042a1eab1cb7982711a1347e242f8947b54b6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="723ba1d50268911818ebdca474fb7656df6050cb" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="smsl" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 14 Feb 2025 02:46:15 PM CET" VOLUMIO_VERSION="3.789" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR_MODEL="SMSL S100" VOLUMIO_VENDOR="SMSL" VOLUMIO_MODEL="S100" VOLUMIO_HASH="215d731aee688e00fb3cc923952be9a7"