Oct 14 21:30:01 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 14 21:30:01 volumio sshd[14546]: Received disconnect from 10.0.0.219 port 51362:11: disconnected by user Oct 14 21:30:01 volumio sshd[14546]: Disconnected from user volumio 10.0.0.219 port 51362 Oct 14 21:30:01 volumio sshd[14535]: pam_unix(sshd:session): session closed for user volumio Oct 14 21:30:01 volumio systemd-logind[725]: Session 22 logged out. Waiting for processes to exit. Oct 14 21:30:01 volumio systemd[1]: session-22.scope: Deactivated successfully. Oct 14 21:30:01 volumio systemd[1]: session-22.scope: Consumed 37.481s CPU time. Oct 14 21:30:01 volumio systemd-logind[725]: Removed session 22. Oct 14 21:30:06 volumio volumio[14769]: verbose: New Socket.io Connection to 10.0.0.163:3000 from 10.0.0.143 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Oct 14 21:30:06 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Oct 14 21:30:06 volumio volumio[14769]: info: CoreCommandRouter::volumioGetState Oct 14 21:30:06 volumio volumio[14769]: info: CorePlayQueue::getTrack 0 Oct 14 21:30:06 volumio volumio[14769]: BT PLUGIN MESSAGE: SYNC attempt 3 err=Command failed: /bin/busctl tree org.bluez 2>/dev/null | grep -oE "/org/bluez/hc out=empty Oct 14 21:30:07 volumio volumio[14769]: info: Discovery: adding ee9a8fd9-9f54-4a6c-8d23-29bf72a01551 Oct 14 21:30:07 volumio volumio[14769]: info: Discovery: Found device Volumiopc Oct 14 21:30:11 volumio systemd[1]: Stopping user@1000.service - User Manager for UID 1000... Oct 14 21:30:11 volumio systemd[14452]: Activating special unit exit.target... Oct 14 21:30:11 volumio systemd[14452]: Stopped target default.target - Main User Target. Oct 14 21:30:11 volumio systemd[14452]: Stopped target basic.target - Basic System. Oct 14 21:30:11 volumio systemd[14452]: Stopped target paths.target - Paths. Oct 14 21:30:11 volumio systemd[14452]: Stopped target sockets.target - Sockets. Oct 14 21:30:11 volumio systemd[14452]: Stopped target timers.target - Timers. Oct 14 21:30:11 volumio systemd[14452]: Closed dirmngr.socket - GnuPG network certificate management daemon. Oct 14 21:30:11 volumio systemd[14452]: Closed gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Oct 14 21:30:11 volumio systemd[14452]: Closed gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Oct 14 21:30:11 volumio systemd[14452]: Closed gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Oct 14 21:30:11 volumio volumio[14769]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 14 21:30:11 volumio systemd[14452]: Closed gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Oct 14 21:30:11 volumio systemd[14452]: Removed slice app.slice - User Application Slice. Oct 14 21:30:11 volumio systemd[14452]: Reached target shutdown.target - Shutdown. Oct 14 21:30:11 volumio systemd[14452]: Finished systemd-exit.service - Exit the Session. Oct 14 21:30:11 volumio systemd[14452]: Reached target exit.target - Exit the Session. Oct 14 21:30:11 volumio systemd[1]: user@1000.service: Deactivated successfully. Oct 14 21:30:11 volumio systemd[1]: Stopped user@1000.service - User Manager for UID 1000. Oct 14 21:30:11 volumio systemd[1]: user@1000.service: Consumed 1.584s CPU time. Oct 14 21:30:12 volumio systemd[1]: Stopping user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... Oct 14 21:30:12 volumio volumio[14769]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 14 21:30:12 volumio systemd[1]: run-user-1000.mount: Deactivated successfully. Oct 14 21:30:12 volumio systemd[1]: user-runtime-dir@1000.service: Deactivated successfully. Oct 14 21:30:12 volumio systemd[1]: Stopped user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. Oct 14 21:30:12 volumio systemd[1]: Removed slice user-1000.slice - User Slice of UID 1000. Oct 14 21:30:12 volumio systemd[1]: user-1000.slice: Consumed 42.859s CPU time. Oct 14 21:30:18 volumio kernel: hwmon hwmon1: Voltage normalised Oct 14 21:30:18 volumio sshd[15318]: Accepted password for volumio from 10.0.0.219 port 51503 ssh2 Oct 14 21:30:18 volumio sshd[15317]: Accepted password for volumio from 10.0.0.219 port 51501 ssh2 Oct 14 21:30:18 volumio sshd[15318]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0) Oct 14 21:30:18 volumio sshd[15317]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0) Oct 14 21:30:19 volumio systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. Oct 14 21:30:19 volumio systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... Oct 14 21:30:19 volumio volumio[14769]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 14 21:30:19 volumio systemd-logind[725]: New session 23 of user volumio. Oct 14 21:30:19 volumio volumio[14769]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 14 21:30:19 volumio volumio[14769]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 14 21:30:19 volumio systemd-logind[725]: New session 24 of user volumio. Oct 14 21:30:19 volumio volumio[14769]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 14 21:30:19 volumio volumio[14769]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 14 21:30:19 volumio systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. Oct 14 21:30:19 volumio systemd[1]: Starting user@1000.service - User Manager for UID 1000... Oct 14 21:30:19 volumio volumio[14769]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 14 21:30:19 volumio (systemd)[15322]: pam_unix(systemd-user:session): session opened for user volumio(uid=1000) by (uid=0) Oct 14 21:30:20 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 14 21:30:20 volumio systemd[15322]: Queued start job for default target default.target. Oct 14 21:30:20 volumio systemd[15322]: Created slice app.slice - User Application Slice. Oct 14 21:30:20 volumio systemd[15322]: Reached target paths.target - Paths. Oct 14 21:30:20 volumio systemd[15322]: Reached target timers.target - Timers. Oct 14 21:30:20 volumio systemd[15322]: Listening on dirmngr.socket - GnuPG network certificate management daemon. Oct 14 21:30:20 volumio systemd[15322]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Oct 14 21:30:20 volumio systemd[15322]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Oct 14 21:30:20 volumio systemd[15322]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Oct 14 21:30:20 volumio systemd[15322]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Oct 14 21:30:20 volumio systemd[15322]: Reached target sockets.target - Sockets. Oct 14 21:30:20 volumio systemd[15322]: Reached target basic.target - Basic System. Oct 14 21:30:20 volumio systemd[1]: Started user@1000.service - User Manager for UID 1000. Oct 14 21:30:20 volumio systemd[1]: Started session-23.scope - Session 23 of User volumio. Oct 14 21:30:20 volumio systemd[15322]: Started mpris-proxy.service - Bluetooth mpris proxy. Oct 14 21:30:20 volumio systemd[15322]: Reached target default.target - Main User Target. Oct 14 21:30:20 volumio systemd[15322]: Startup finished in 1.421s. Oct 14 21:30:20 volumio systemd[1]: Started session-24.scope - Session 24 of User volumio. Oct 14 21:30:20 volumio mpris-proxy[15337]: Can't get on session bus Oct 14 21:30:20 volumio systemd[15322]: mpris-proxy.service: Main process exited, code=exited, status=1/FAILURE Oct 14 21:30:20 volumio systemd[15322]: mpris-proxy.service: Failed with result 'exit-code'. Oct 14 21:30:21 volumio sshd[15318]: pam_env(sshd:session): deprecated reading of user environment enabled Oct 14 21:30:21 volumio sshd[15317]: pam_env(sshd:session): deprecated reading of user environment enabled Oct 14 21:30:22 volumio sshd[15357]: Received disconnect from 10.0.0.219 port 51501:11: disconnected by user Oct 14 21:30:22 volumio sshd[15357]: Disconnected from user volumio 10.0.0.219 port 51501 Oct 14 21:30:22 volumio sshd[15317]: pam_unix(sshd:session): session closed for user volumio Oct 14 21:30:22 volumio systemd[1]: session-24.scope: Deactivated successfully. Oct 14 21:30:22 volumio systemd[1]: session-24.scope: Consumed 1.203s CPU time. Oct 14 21:30:22 volumio systemd-logind[725]: Session 24 logged out. Waiting for processes to exit. Oct 14 21:30:22 volumio systemd-logind[725]: Removed session 24. Oct 14 21:30:22 volumio volumio[14769]: info: Discovery: A device disappeared from network Oct 14 21:30:23 volumio volumio[14769]: verbose: New Socket.io Connection to 10.0.0.163:3000 from 10.0.0.143 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 12 Oct 14 21:30:24 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket Oct 14 21:30:24 volumio volumio[14769]: info: CoreCommandRouter::volumioGetState Oct 14 21:30:24 volumio volumio[14769]: info: CorePlayQueue::getTrack 0 Oct 14 21:30:24 volumio volumio[14769]: info: Discovery: adding ee9a8fd9-9f54-4a6c-8d23-29bf72a01551 Oct 14 21:30:24 volumio volumio[14769]: info: Discovery: Found device Volumiopc Oct 14 21:30:27 volumio volumio[14769]: info: Discovery: Disconnected from remote: 10.0.0.143 Oct 14 21:30:28 volumio sshd[15353]: Received disconnect from 10.0.0.219 port 51503:11: disconnected by user Oct 14 21:30:28 volumio sshd[15353]: Disconnected from user volumio 10.0.0.219 port 51503 Oct 14 21:30:28 volumio sshd[15318]: pam_unix(sshd:session): session closed for user volumio Oct 14 21:30:28 volumio systemd[1]: session-23.scope: Deactivated successfully. Oct 14 21:30:28 volumio systemd[1]: session-23.scope: Consumed 6.030s CPU time. Oct 14 21:30:28 volumio systemd-logind[725]: Session 23 logged out. Waiting for processes to exit. Oct 14 21:30:28 volumio systemd-logind[725]: Removed session 23. Oct 14 21:30:28 volumio volumio[14769]: info: MRS: Pushing audio output on request Oct 14 21:30:28 volumio volumio[14769]: info: MRS: Pushing multiroomSync output Oct 14 21:30:28 volumio volumio[14769]: info: Discovery: Connected to remote: 10.0.0.143 Oct 14 21:30:30 volumio kernel: hwmon hwmon1: Voltage normalised Oct 14 21:30:34 volumio volumio[14769]: info: MRS: Adding multiroomSync output Oct 14 21:30:34 volumio volumio[14769]: info: Adding audio output: Oct 14 21:30:34 volumio volumio[14769]: info: MRS: Pushing multiroomSync output Oct 14 21:30:35 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 14 21:30:37 volumio volumio[14769]: info: MRS: Updating multiroomSync output Oct 14 21:30:37 volumio volumio[14769]: info: MRS: Updating multiroomSync output Oct 14 21:30:38 volumio systemd[1]: Stopping user@1000.service - User Manager for UID 1000... Oct 14 21:30:38 volumio systemd[15322]: Activating special unit exit.target... Oct 14 21:30:38 volumio systemd[15322]: Stopped target default.target - Main User Target. Oct 14 21:30:38 volumio systemd[15322]: Stopped target basic.target - Basic System. Oct 14 21:30:38 volumio systemd[15322]: Stopped target paths.target - Paths. Oct 14 21:30:38 volumio systemd[15322]: Stopped target sockets.target - Sockets. Oct 14 21:30:38 volumio systemd[15322]: Stopped target timers.target - Timers. Oct 14 21:30:38 volumio systemd[15322]: Closed dirmngr.socket - GnuPG network certificate management daemon. Oct 14 21:30:38 volumio systemd[15322]: Closed gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Oct 14 21:30:38 volumio systemd[15322]: Closed gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Oct 14 21:30:38 volumio systemd[15322]: Closed gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Oct 14 21:30:38 volumio systemd[15322]: Closed gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Oct 14 21:30:38 volumio systemd[15322]: Removed slice app.slice - User Application Slice. Oct 14 21:30:38 volumio systemd[15322]: Reached target shutdown.target - Shutdown. Oct 14 21:30:38 volumio systemd[15322]: Finished systemd-exit.service - Exit the Session. Oct 14 21:30:38 volumio systemd[15322]: Reached target exit.target - Exit the Session. Oct 14 21:30:38 volumio volumio[14769]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 14 21:30:38 volumio systemd[1]: user@1000.service: Deactivated successfully. Oct 14 21:30:38 volumio systemd[1]: Stopped user@1000.service - User Manager for UID 1000. Oct 14 21:30:38 volumio systemd[1]: user@1000.service: Consumed 1.491s CPU time. Oct 14 21:30:39 volumio systemd[1]: Stopping user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... Oct 14 21:30:39 volumio volumio[14769]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 14 21:30:39 volumio systemd[1]: run-user-1000.mount: Deactivated successfully. Oct 14 21:30:39 volumio systemd[1]: user-runtime-dir@1000.service: Deactivated successfully. Oct 14 21:30:39 volumio systemd[1]: Stopped user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. Oct 14 21:30:39 volumio systemd[1]: Removed slice user-1000.slice - User Slice of UID 1000. Oct 14 21:30:39 volumio systemd[1]: user-1000.slice: Consumed 8.831s CPU time. Oct 14 21:30:39 volumio volumio[14769]: info: MRS: Pushing audio output on request Oct 14 21:30:39 volumio volumio[14769]: info: MRS: Pushing multiroomSync output Oct 14 21:30:39 volumio volumio[14769]: info: MRS: Pushing audio output on request Oct 14 21:30:39 volumio volumio[14769]: info: MRS: Pushing multiroomSync output Oct 14 21:30:49 volumio sshd[15514]: Accepted password for volumio from 10.0.0.219 port 51533 ssh2 Oct 14 21:30:49 volumio sshd[15514]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0) Oct 14 21:30:49 volumio systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. Oct 14 21:30:50 volumio systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... Oct 14 21:30:50 volumio volumio[14769]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 14 21:30:50 volumio systemd-logind[725]: New session 26 of user volumio. Oct 14 21:30:50 volumio volumio[14769]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 14 21:30:50 volumio volumio[14769]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 14 21:30:50 volumio systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. Oct 14 21:30:50 volumio systemd[1]: Starting user@1000.service - User Manager for UID 1000... Oct 14 21:30:50 volumio volumio[14769]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 14 21:30:50 volumio (systemd)[15517]: pam_unix(systemd-user:session): session opened for user volumio(uid=1000) by (uid=0) Oct 14 21:30:51 volumio systemd[15517]: Queued start job for default target default.target. Oct 14 21:30:51 volumio systemd[15517]: Created slice app.slice - User Application Slice. Oct 14 21:30:51 volumio systemd[15517]: Reached target paths.target - Paths. Oct 14 21:30:51 volumio systemd[15517]: Reached target timers.target - Timers. Oct 14 21:30:51 volumio systemd[15517]: Listening on dirmngr.socket - GnuPG network certificate management daemon. Oct 14 21:30:51 volumio systemd[15517]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Oct 14 21:30:51 volumio systemd[15517]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Oct 14 21:30:51 volumio systemd[15517]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Oct 14 21:30:51 volumio systemd[15517]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Oct 14 21:30:51 volumio systemd[15517]: Reached target sockets.target - Sockets. Oct 14 21:30:51 volumio systemd[15517]: Reached target basic.target - Basic System. Oct 14 21:30:51 volumio systemd[1]: Started user@1000.service - User Manager for UID 1000. Oct 14 21:30:51 volumio systemd[15517]: Started mpris-proxy.service - Bluetooth mpris proxy. Oct 14 21:30:51 volumio systemd[15517]: Reached target default.target - Main User Target. Oct 14 21:30:51 volumio systemd[15517]: Startup finished in 1.414s. Oct 14 21:30:51 volumio systemd[1]: Started session-26.scope - Session 26 of User volumio. Oct 14 21:30:51 volumio mpris-proxy[15534]: Can't get on session bus Oct 14 21:30:51 volumio systemd[15517]: mpris-proxy.service: Main process exited, code=exited, status=1/FAILURE Oct 14 21:30:51 volumio systemd[15517]: mpris-proxy.service: Failed with result 'exit-code'. Oct 14 21:30:51 volumio sshd[15514]: pam_env(sshd:session): deprecated reading of user environment enabled Oct 14 21:30:51 volumio sudo[15546]: volumio : PWD=/home/volumio ; USER=root ; COMMAND=/bin/journalctl -u volumio --no-pager -n 400 Oct 14 21:30:51 volumio sudo[15546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 21:30:52 volumio sudo[15546]: pam_unix(sudo:session): session closed for user root Oct 14 21:30:53 volumio sshd[15544]: Received disconnect from 10.0.0.219 port 51533:11: disconnected by user Oct 14 21:30:53 volumio sshd[15544]: Disconnected from user volumio 10.0.0.219 port 51533 Oct 14 21:30:53 volumio sshd[15514]: pam_unix(sshd:session): session closed for user volumio Oct 14 21:30:53 volumio systemd[1]: session-26.scope: Deactivated successfully. Oct 14 21:30:53 volumio systemd[1]: session-26.scope: Consumed 1.407s CPU time. Oct 14 21:30:53 volumio systemd-logind[725]: Session 26 logged out. Waiting for processes to exit. Oct 14 21:30:53 volumio systemd-logind[725]: Removed session 26. Oct 14 21:30:59 volumio kernel: hwmon hwmon1: Voltage normalised Oct 14 21:31:03 volumio systemd[1]: Stopping user@1000.service - User Manager for UID 1000... Oct 14 21:31:03 volumio systemd[15517]: Activating special unit exit.target... Oct 14 21:31:03 volumio volumio[14769]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 14 21:31:03 volumio systemd[15517]: Stopped target default.target - Main User Target. Oct 14 21:31:03 volumio systemd[15517]: Stopped target basic.target - Basic System. Oct 14 21:31:03 volumio systemd[15517]: Stopped target paths.target - Paths. Oct 14 21:31:03 volumio systemd[15517]: Stopped target sockets.target - Sockets. Oct 14 21:31:03 volumio systemd[15517]: Stopped target timers.target - Timers. Oct 14 21:31:03 volumio systemd[15517]: Closed dirmngr.socket - GnuPG network certificate management daemon. Oct 14 21:31:03 volumio systemd[15517]: Closed gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Oct 14 21:31:03 volumio systemd[15517]: Closed gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Oct 14 21:31:03 volumio systemd[15517]: Closed gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Oct 14 21:31:03 volumio systemd[15517]: Closed gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Oct 14 21:31:03 volumio systemd[15517]: Removed slice app.slice - User Application Slice. Oct 14 21:31:03 volumio systemd[15517]: Reached target shutdown.target - Shutdown. Oct 14 21:31:03 volumio systemd[15517]: Finished systemd-exit.service - Exit the Session. Oct 14 21:31:03 volumio systemd[15517]: Reached target exit.target - Exit the Session. Oct 14 21:31:03 volumio systemd[1]: user@1000.service: Deactivated successfully. Oct 14 21:31:03 volumio systemd[1]: Stopped user@1000.service - User Manager for UID 1000. Oct 14 21:31:03 volumio systemd[1]: user@1000.service: Consumed 1.480s CPU time. Oct 14 21:31:03 volumio systemd[1]: Stopping user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... Oct 14 21:31:03 volumio volumio[14769]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 14 21:31:03 volumio systemd[1]: run-user-1000.mount: Deactivated successfully. Oct 14 21:31:03 volumio systemd[1]: user-runtime-dir@1000.service: Deactivated successfully. Oct 14 21:31:03 volumio systemd[1]: Stopped user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. Oct 14 21:31:03 volumio systemd[1]: Removed slice user-1000.slice - User Slice of UID 1000. Oct 14 21:31:03 volumio systemd[1]: user-1000.slice: Consumed 2.995s CPU time. Oct 14 21:31:04 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 14 21:31:10 volumio kernel: hwmon hwmon1: Voltage normalised Oct 14 21:31:14 volumio volumio[14769]: info: Preload queue cleared Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::volumioReplaceandPlayItems Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::ClearQueue Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::stop Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 21:31:14 volumio volumio[14769]: info: CorePlayQueue::clearPlayQueue Oct 14 21:31:14 volumio volumio[14769]: info: CorePlayQueue::saveQueue Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::volumioPushQueue Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::addQueueItems Oct 14 21:31:14 volumio volumio[14769]: info: CorePlayQueue::addQueueItems Oct 14 21:31:14 volumio volumio[14769]: info: Preload queue cleared Oct 14 21:31:14 volumio volumio[14769]: info: Adding Item to queue: upnp/folder/http://10.0.0.2:50001/ContentDirectory/control@22$13274 Oct 14 21:31:14 volumio volumio[14769]: info: Exploding uri upnp/folder/http://10.0.0.2:50001/ContentDirectory/control@22$13274 in service upnp_browser Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::volumioPushQueue Oct 14 21:31:14 volumio volumio[14769]: info: CorePlayQueue::saveQueue Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::updateTrackBlock Oct 14 21:31:14 volumio volumio[14769]: info: CorePlayQueue::getTrackBlock Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::volumioPlay Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::play index 0 Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::stop Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::play index undefined Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 14 21:31:14 volumio volumio[14769]: info: CorePlayQueue::getTrack 0 Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::startPlaybackTimer Oct 14 21:31:14 volumio volumio[14769]: info: CorePlayQueue::getTrack 0 Oct 14 21:31:14 volumio volumio[14769]: info: [1791984674224] ControllerUPNPBrowser::clearAddPlayTrack Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::sendMpdCommand stop Oct 14 21:31:14 volumio volumio[14769]: info: sendMpdCommand stop took 15 milliseconds Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::sendMpdCommand clear Oct 14 21:31:14 volumio volumio[14769]: info: Oct 14 21:31:14 volumio volumio[14769]: ---------------------------- MPD announces system playlist update Oct 14 21:31:14 volumio volumio[14769]: info: Ignoring MPD Status Update Oct 14 21:31:14 volumio volumio[14769]: info: sendMpdCommand clear took 8 milliseconds Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::sendMpdCommand load "http://10.0.0.2:50002/m/NDLNA/38329.flac" Oct 14 21:31:14 volumio volumio[14769]: error: updateQueue error: null Oct 14 21:31:14 volumio volumio[14769]: info: ------------------------------ 36ms Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::sendMpdCommand add "http://10.0.0.2:50002/m/NDLNA/38329.flac" Oct 14 21:31:14 volumio volumio[14769]: info: Oct 14 21:31:14 volumio volumio[14769]: ---------------------------- MPD announces system playlist update Oct 14 21:31:14 volumio volumio[14769]: info: Ignoring MPD Status Update Oct 14 21:31:14 volumio volumio[14769]: info: sendMpdCommand add "http://10.0.0.2:50002/m/NDLNA/38329.flac" took 4 milliseconds Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::sendMpdCommand play Oct 14 21:31:14 volumio volumio[14769]: info: ------------------------------ 12ms Oct 14 21:31:14 volumio volumio[14769]: info: sendMpdCommand play took 10 milliseconds Oct 14 21:31:14 volumio volumio[14769]: info: Oct 14 21:31:14 volumio volumio[14769]: ---------------------------- MPD announces state update: player Oct 14 21:31:14 volumio volumio[14769]: info: ControllerMpd::getState Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::sendMpdCommand status Oct 14 21:31:14 volumio volumio[14769]: info: Oct 14 21:31:14 volumio volumio[14769]: ---------------------------- MPD announces state update: player Oct 14 21:31:14 volumio volumio[14769]: info: sendMpdCommand status took 68 milliseconds Oct 14 21:31:14 volumio volumio[14769]: info: ControllerMpd::getState Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::sendMpdCommand status Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::parseState Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 21:31:14 volumio volumio[14769]: info: Oct 14 21:31:14 volumio volumio[14769]: ---------------------------- MPD announces system playlist update Oct 14 21:31:14 volumio volumio[14769]: info: Ignoring MPD Status Update Oct 14 21:31:14 volumio volumio[14769]: info: Oct 14 21:31:14 volumio volumio[14769]: ---------------------------- MPD announces state update: player Oct 14 21:31:14 volumio volumio[14769]: info: ControllerMpd::getState Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::sendMpdCommand status Oct 14 21:31:14 volumio volumio[14769]: info: sendMpdCommand status took 41 milliseconds Oct 14 21:31:14 volumio volumio[14769]: info: sendMpdCommand playlistinfo took 33 milliseconds Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::parseState Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::parseTrackInfo Oct 14 21:31:14 volumio volumio[14769]: info: ControllerMpd::pushState Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::servicePushState Oct 14 21:31:14 volumio volumio[14769]: info: CorePlayQueue::getTrack 0 Oct 14 21:31:14 volumio volumio[14769]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":377,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"欸乃","artist":"瑞鸣唱片","album":"天人合一","uri":"http://10.0.0.2:50002/m/NDLNA/38329.flac","trackType":"flac"} Oct 14 21:31:14 volumio volumio[14769]: verbose: CURRENT POSITION 0 Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::syncState stateService play Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::syncState currentStatus stop Oct 14 21:31:14 volumio volumio[14769]: info: ------------------------------ 169ms Oct 14 21:31:14 volumio volumio[14769]: info: ------------------------------ 86ms Oct 14 21:31:14 volumio volumio[14769]: info: sendMpdCommand status took 77 milliseconds Oct 14 21:31:14 volumio volumio[14769]: info: sendMpdCommand playlistinfo took 53 milliseconds Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::parseState Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::parseTrackInfo Oct 14 21:31:14 volumio kernel: hwmon hwmon1: Undervoltage detected! Oct 14 21:31:14 volumio volumio[14769]: info: ControllerMpd::pushState Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::servicePushState Oct 14 21:31:14 volumio volumio[14769]: info: CorePlayQueue::getTrack 0 Oct 14 21:31:14 volumio volumio[14769]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1215,"duration":377,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"208 Kbps","isStreaming":false,"title":"欸乃","artist":"瑞鸣唱片","album":"天人合一","uri":"http://10.0.0.2:50002/m/NDLNA/38329.flac","trackType":"flac"} Oct 14 21:31:14 volumio volumio[14769]: verbose: CURRENT POSITION 0 Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::syncState stateService play Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::syncState currentStatus play Oct 14 21:31:14 volumio volumio[14769]: info: Received an update from plugin. extracting info from payload Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::pushState Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::volumioPushState Oct 14 21:31:14 volumio volumio[14769]: info: MRS: Pushing multiroomSync output update for this device Oct 14 21:31:14 volumio volumio[14769]: info: MRS: Pushing multiroomSync output Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::volumioGetState Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::pushState Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::volumioPushState Oct 14 21:31:14 volumio volumio[14769]: info: MRS: Pushing multiroomSync output update for this device Oct 14 21:31:14 volumio volumio[14769]: info: MRS: Pushing multiroomSync output Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::volumioGetState Oct 14 21:31:14 volumio volumio[14769]: info: ------------------------------ 451ms Oct 14 21:31:14 volumio volumio[14769]: info: sendMpdCommand playlistinfo took 329 milliseconds Oct 14 21:31:14 volumio volumio[14769]: verbose: ControllerMpd::parseTrackInfo Oct 14 21:31:14 volumio volumio[14769]: info: ControllerMpd::pushState Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::servicePushState Oct 14 21:31:14 volumio volumio[14769]: info: CorePlayQueue::getTrack 0 Oct 14 21:31:14 volumio volumio[14769]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1215,"duration":377,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"208 Kbps","isStreaming":false,"title":"欸乃","artist":"瑞鸣唱片","album":"天人合一","uri":"http://10.0.0.2:50002/m/NDLNA/38329.flac","trackType":"flac"} Oct 14 21:31:14 volumio volumio[14769]: verbose: CURRENT POSITION 0 Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::syncState stateService play Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::syncState currentStatus play Oct 14 21:31:14 volumio volumio[14769]: info: Received an update from plugin. extracting info from payload Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::pushState Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::volumioPushState Oct 14 21:31:14 volumio volumio[14769]: info: MRS: Pushing multiroomSync output update for this device Oct 14 21:31:14 volumio volumio[14769]: info: MRS: Pushing multiroomSync output Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::volumioGetState Oct 14 21:31:14 volumio volumio[14769]: info: CoreStateMachine::pushState Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::volumioPushState Oct 14 21:31:14 volumio volumio[14769]: info: MRS: Pushing multiroomSync output update for this device Oct 14 21:31:14 volumio volumio[14769]: info: MRS: Pushing multiroomSync output Oct 14 21:31:14 volumio volumio[14769]: info: CoreCommandRouter::volumioGetState Oct 14 21:31:15 volumio volumio[14769]: info: ------------------------------ 591ms Oct 14 21:31:15 volumio volumio[14769]: info: CoreCommandRouter::volumioGetQueue Oct 14 21:31:15 volumio volumio[14769]: info: CoreStateMachine::getQueue Oct 14 21:31:15 volumio volumio[14769]: info: CorePlayQueue::getQueue Oct 14 21:31:15 volumio volumio[14769]: info: CoreCommandRouter::volumioGetQueue Oct 14 21:31:15 volumio volumio[14769]: info: CoreStateMachine::getQueue Oct 14 21:31:15 volumio volumio[14769]: info: CorePlayQueue::getQueue Oct 14 21:31:15 volumio volumio[14769]: info: CoreCommandRouter::volumioGetQueue Oct 14 21:31:15 volumio volumio[14769]: info: CoreStateMachine::getQueue Oct 14 21:31:15 volumio volumio[14769]: info: CorePlayQueue::getQueue Oct 14 21:31:15 volumio volumio[14769]: info: CoreCommandRouter::volumioGetQueue Oct 14 21:31:15 volumio volumio[14769]: info: CoreStateMachine::getQueue Oct 14 21:31:15 volumio volumio[14769]: info: CorePlayQueue::getQueue Oct 14 21:31:20 volumio volumio[14769]: info: CoreCommandRouter::volumioGetState Oct 14 21:31:22 volumio volumio[14769]: info: Executing endpoint metavolumio Oct 14 21:31:22 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 14 21:31:22 volumio volumio[14769]: info: Executing endpoint metavolumio Oct 14 21:31:22 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 14 21:31:22 volumio volumio[14769]: info: Executing endpoint metavolumio Oct 14 21:31:22 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Oct 14 21:31:31 volumio volumio[14769]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 14 21:31:31 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 14 21:31:31 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 14 21:31:31 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 14 21:31:31 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Oct 14 21:31:31 volumio volumio[14769]: info: Received Get System Version Oct 14 21:31:31 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 14 21:31:32 volumio ntpd[905]: DNS: dns_probe: 3.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 14 21:31:32 volumio ntpd[905]: DNS: dns_check: processing 3.debian.pool.ntp.org, 8, 101 Oct 14 21:31:32 volumio ntpd[905]: DNS: Pool skipping: 198.18.2.172 Oct 14 21:31:32 volumio ntpd[905]: DNS: dns_take_status: 3.debian.pool.ntp.org=>good, 8 Oct 14 21:31:33 volumio ntpd[905]: DNS: dns_probe: 2.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 14 21:31:33 volumio ntpd[905]: DNS: dns_check: processing 2.debian.pool.ntp.org, 8, 101 Oct 14 21:31:33 volumio ntpd[905]: DNS: Pool skipping: 198.18.2.173 Oct 14 21:31:33 volumio ntpd[905]: DNS: dns_take_status: 2.debian.pool.ntp.org=>good, 8 Oct 14 21:31:34 volumio ntpd[905]: DNS: dns_probe: 1.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 14 21:31:34 volumio ntpd[905]: DNS: dns_check: processing 1.debian.pool.ntp.org, 8, 101 Oct 14 21:31:34 volumio ntpd[905]: DNS: Pool skipping: 198.18.2.174 Oct 14 21:31:34 volumio ntpd[905]: DNS: dns_take_status: 1.debian.pool.ntp.org=>good, 8 Oct 14 21:31:35 volumio ntpd[905]: DNS: dns_probe: 0.debian.pool.ntp.org, cast_flags:8, flags:101 Oct 14 21:31:35 volumio ntpd[905]: DNS: dns_check: processing 0.debian.pool.ntp.org, 8, 101 Oct 14 21:31:35 volumio ntpd[905]: DNS: Pool skipping: 198.18.2.175 Oct 14 21:31:35 volumio ntpd[905]: DNS: dns_take_status: 0.debian.pool.ntp.org=>good, 8 Oct 14 21:31:40 volumio volumio[14769]: info: CALLMETHOD: system_controller system savePrivacySettings [object Object] Oct 14 21:31:40 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: system , savePrivacySettings Oct 14 21:31:40 volumio volumio[14769]: info: CoreCommandRouter::Reload Ui Oct 14 21:31:41 volumio sudo[15671]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 14 21:31:41 volumio sudo[15671]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 21:31:41 volumio sudo[15671]: pam_unix(sudo:session): session closed for user root Oct 14 21:31:41 volumio sudo[15673]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 14 21:31:41 volumio sudo[15673]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Oct 14 21:31:41 volumio sudo[15673]: pam_unix(sudo:session): session closed for user root Oct 14 21:31:41 volumio volumio[14769]: verbose: New Socket.io Connection to 10.0.0.163 from 10.0.0.238 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/155.0.0.0 Safari/537.36 Edg/155.0.0.0 Engine version: 3 Transport: polling Total Clients: 6 Oct 14 21:31:41 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 14 21:31:41 volumio volumio[14769]: info: CoreCommandRouter::volumioGetVisibleSources Oct 14 21:31:41 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 14 21:31:41 volumio volumio[14769]: info: CoreCommandRouter::volumioGetState Oct 14 21:31:41 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 14 21:31:41 volumio volumio[14769]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 14 21:31:41 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 14 21:31:41 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 14 21:31:41 volumio volumio[14769]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getDevices Oct 14 21:31:41 volumio volumio[14769]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 14 21:31:41 volumio volumio[14769]: TypeError: self.commandRouter.executeOnPlugin(...).then is not a function Oct 14 21:31:41 volumio volumio[14769]: at my_module.getMultiroom (/myvolumio/plugins/audio_interface/multiroom/index.js:13:14) Oct 14 21:31:41 volumio volumio[14769]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1096:32) Oct 14 21:31:41 volumio volumio[14769]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:811:45) Oct 14 21:31:41 volumio volumio[14769]: at Socket.emit (node:events:514:28) Oct 14 21:31:41 volumio volumio[14769]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Oct 14 21:31:41 volumio volumio[14769]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Oct 14 21:31:41 volumio volumio[14769]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 14 21:31:43 volumio sudo[15690]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-10-14 21:30' Oct 14 21:31:43 volumio sudo[15690]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="18952480e8d8c63f22208e9007a0f47a9563eae6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026" VOLUMIO_VERSION="4.119" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"