-- Logs begin at Wed 2025-10-29 09:35:27 JST, end at Wed 2025-10-29 09:37:51 JST. -- Oct 29 09:36:00 volumio volumio[1322]: info: Loading plugin "jp_radio"... Oct 29 09:36:00 volumio volumio[1322]: Forking 3 albumart workers Oct 29 09:36:00 volumio systemd[1]: systemd-fsckd.service: Succeeded. Oct 29 09:36:02 volumio volumio[1322]: Starting albumart workers Oct 29 09:36:02 volumio volumio[1322]: Starting albumart workers Oct 29 09:36:02 volumio volumio[1322]: Starting albumart workers Oct 29 09:36:03 volumio volumio-remote-updater[737]: [2025-10-29 09:36:03] [connect] Successful connection Oct 29 09:36:04 volumio volumio[1322]: info: Loading plugin "lms"... Oct 29 09:36:05 volumio volumio[1322]: info: Loading i18n strings for locale ja Oct 29 09:36:05 volumio volumio[1322]: Updating browse sources language Oct 29 09:36:05 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 29 09:36:05 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 29 09:36:05 volumio volumio[1322]: info: CoreCommandRouter::initPlayerControls Oct 29 09:36:05 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:05 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:05 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:05 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:05 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:05 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:05 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:05 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:05 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 29 09:36:06 volumio volumio[1322]: Express server listening on port 3000 Oct 29 09:36:06 volumio volumio[1322]: [Metrics] WebUI: 18s 181.87ms Oct 29 09:36:06 volumio volumio[1322]: info: CoreStateMachine::resetVolumioState Oct 29 09:36:06 volumio volumio[1322]: info: CoreStateMachine::getcurrentVolume Oct 29 09:36:06 volumio volumio[1322]: info: CoreCommandRouter::volumioRetrievevolume Oct 29 09:36:06 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:06 volumio volumio[1322]: error: Cannot read config.txt file: Error: ENOENT: no such file or directory, open '/boot/config.txt' Oct 29 09:36:06 volumio volumio[1322]: info: Completed loading Core Plugins Oct 29 09:36:06 volumio volumio[1322]: info: Preparing to generate the ALSA configuration file Oct 29 09:36:06 volumio volumio[1322]: info: Volumio Network Manager: Network status updated: 1 Oct 29 09:36:06 volumio volumio[1322]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Oct 29 09:36:06 volumio volumio[1322]: wlan0 Interface doesn't support scanning. Oct 29 09:36:06 volumio volumio[1322]: info: Cannot use regular scanning, forcing with ap-force Oct 29 09:36:06 volumio sudo[1538]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Oct 29 09:36:06 volumio sudo[1538]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 09:36:06 volumio sudo[1538]: pam_unix(sudo:session): session closed for user root Oct 29 09:36:06 volumio volumio[1322]: command failed: No such device (-19) Oct 29 09:36:06 volumio volumio[1322]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Oct 29 09:36:06 volumio volumio[1322]: command failed: No such device (-19) Oct 29 09:36:06 volumio sudo[1544]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 29 09:36:06 volumio sudo[1544]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 09:36:06 volumio sudo[1544]: pam_unix(sudo:session): session closed for user root Oct 29 09:36:06 volumio sudo[1546]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 29 09:36:06 volumio sudo[1546]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 09:36:06 volumio sudo[1546]: pam_unix(sudo:session): session closed for user root Oct 29 09:36:06 volumio volumio[1322]: verbose: New Socket.io Connection to 192.168.223.251 from 192.168.223.62 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.6 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 1 Oct 29 09:36:06 volumio volumio[1322]: verbose: New Socket.io Connection to 192.168.223.251 from 192.168.223.62 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.6 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 2 Oct 29 09:36:06 volumio volumio[1322]: verbose: New Socket.io Connection to 192.168.223.251 from 192.168.223.62 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.6 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 3 Oct 29 09:36:06 volumio volumio-remote-updater[737]: [2025-10-29 09:36:06] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1761698163 101 Oct 29 09:36:06 volumio volumio[1322]: 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: 4 Oct 29 09:36:06 volumio volumio[1322]: verbose: New Socket.io Connection to 192.168.223.251 from 192.168.223.62 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_6_2 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.6 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 5 Oct 29 09:36:06 volumio volumio[1322]: info: CoreCommandRouter::volumioGetState Oct 29 09:36:06 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:06 volumio volumio[1322]: info: Reloading queue from file Oct 29 09:36:07 volumio volumio[1322]: info: VolumeController:: Volume=0 Mute =false Oct 29 09:36:07 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:36:07 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:36:07 volumio volumio[1322]: info: CoreStateMachine::updateTrackBlock Oct 29 09:36:07 volumio volumio[1322]: info: CorePlayQueue::getTrackBlock Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::volumioRetrievevolume Oct 29 09:36:07 volumio volumio[1322]: info: Asound.conf file unchanged, so no further update is needed Oct 29 09:36:07 volumio volumio[1322]: info: Output device has changed, restarting MPD Oct 29 09:36:07 volumio volumio[1322]: info: Output device has changed, restarting Shairport Sync Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:07 volumio sudo[1565]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 29 09:36:07 volumio sudo[1565]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 09:36:07 volumio sudo[1565]: pam_unix(sudo:session): session closed for user root Oct 29 09:36:07 volumio sudo[1567]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 29 09:36:07 volumio sudo[1567]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 09:36:07 volumio systemd[1]: Stopping Music Player Daemon... Oct 29 09:36:07 volumio volumio[1322]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 29 09:36:07 volumio volumio[1322]: info: ___________ START PLUGINS ___________ Oct 29 09:36:07 volumio volumio[1322]: info: ControllerMpd::onStart: Initializing MPD Oct 29 09:36:07 volumio volumio[1322]: info: Creating MPD Configuration file Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 29 09:36:07 volumio volumio[1322]: info: [1761698167375] CoreMusicLibrary::Adding element DLNAサーバー Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 29 09:36:07 volumio sudo[1574]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 29 09:36:07 volumio sudo[1574]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 09:36:07 volumio sudo[1576]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 29 09:36:07 volumio sudo[1576]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 09:36:07 volumio sudo[1574]: pam_unix(sudo:session): session closed for user root Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:07 volumio volumio[1322]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:07 volumio systemd[1]: mpd.service: Succeeded. Oct 29 09:36:07 volumio systemd[1]: Stopped Music Player Daemon. Oct 29 09:36:07 volumio systemd[1]: Starting Music Player Daemon... Oct 29 09:36:07 volumio volumio[1322]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 29 09:36:07 volumio volumio[1322]: info: [1761698167678] CoreMusicLibrary::Adding element Last_100 Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 29 09:36:07 volumio volumio[1322]: info: [1761698167685] CoreMusicLibrary::Adding element Webradio Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 29 09:36:07 volumio volumio[1322]: info: Initializing BBC Radios Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 29 09:36:07 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:07 volumio sudo[1585]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 29 09:36:07 volumio sudo[1585]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 09:36:07 volumio sudo[1585]: pam_unix(sudo:session): session closed for user root Oct 29 09:36:08 volumio volumio[1322]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 29 09:36:08 volumio volumio[1322]: info: [1761698168034] CoreMusicLibrary::Adding element RADIKO Oct 29 09:36:08 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 29 09:36:08 volumio volumio[1322]: Cannot find translation for source RADIKO Oct 29 09:36:08 volumio volumio[1322]: info: Volumio Calling Home Oct 29 09:36:08 volumio sudo[1599]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart logitechmediaserver Oct 29 09:36:08 volumio sudo[1599]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 09:36:08 volumio systemd[1]: /data/plugins/music_service/lms/unit/logitechmediaserver.service:7: PIDFile= references path below legacy directory /var/run/, updating /var/run/logitechmediaserver.pid → /run/logitechmediaserver.pid; please update the unit file accordingly. Oct 29 09:36:08 volumio systemd[1]: Starting Logitech Media Server Daemon... Oct 29 09:36:08 volumio systemd[1]: Started Logitech Media Server Daemon. Oct 29 09:36:08 volumio sudo[1599]: pam_unix(sudo:session): session closed for user root Oct 29 09:36:08 volumio systemd[1606]: logitechmediaserver.service: Failed to execute command: No such file or directory Oct 29 09:36:08 volumio systemd[1606]: logitechmediaserver.service: Failed at step EXEC spawning /usr/sbin/squeezeboxserver: No such file or directory Oct 29 09:36:08 volumio systemd[1]: logitechmediaserver.service: Main process exited, code=exited, status=203/EXEC Oct 29 09:36:08 volumio systemd[1]: logitechmediaserver.service: Failed with result 'exit-code'. Oct 29 09:36:08 volumio volumio[1322]: info: CoreStateMachine::setRepeat false single undefined Oct 29 09:36:08 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:36:08 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:08 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:36:08 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:36:08 volumio volumio[1322]: info: CoreStateMachine::setRandom null Oct 29 09:36:08 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:36:08 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:08 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:36:08 volumio volumio[1322]: info: logitechmediaserver started Oct 29 09:36:08 volumio volumio[1322]: info: MPD Permissions set Oct 29 09:36:08 volumio volumio[1322]: info: MPD Permissions set Oct 29 09:36:08 volumio volumio[1322]: info: CoreCommandRouter::volumioGetState Oct 29 09:36:08 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:08 volumio volumio[1322]: info: Volumio called home Oct 29 09:36:09 volumio volumio[1322]: info: Discovery: adding 55e405f5-a25e-4eee-b880-50dec7a9cf3e Oct 29 09:36:09 volumio volumio[1322]: info: Discovery: Found device Volumio Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::volumioGetState Oct 29 09:36:09 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:09 volumio sudo[1614]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 29 09:36:09 volumio sudo[1614]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 09:36:09 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Oct 29 09:36:09 volumio sudo[1614]: pam_unix(sudo:session): session closed for user root Oct 29 09:36:09 volumio volumio[1322]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 29 09:36:09 volumio volumio[1322]: info: VolumeController:: Volume=0 Mute =false Oct 29 09:36:09 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:36:09 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 29 09:36:09 volumio cron[771]: 2025-10-29 09:36:09 1vDuAb-0000QC-CI Cannot open main log file "/var/log/exim4/mainlog": Permission denied: euid=118 egid=124 Oct 29 09:36:09 volumio cron[771]: 2025-10-29 09:36:09 1vDuAb-0000QC-CI <= volumio@volumio U=volumio P=local S=659 Oct 29 09:36:09 volumio cron[771]: 2025-10-29 09:36:09 1vDuAb-0000QC-CI Cannot open main log file "/var/log/exim4/mainlog": Permission denied: euid=118 egid=124 Oct 29 09:36:09 volumio cron[771]: exim: could not open panic log - aborting: see message(s) above Oct 29 09:36:09 volumio exim[1624]: 2025-10-29 09:36:09 1vDuAb-0000QC-CI <= volumio@volumio U=volumio P=local S=659 Oct 29 09:36:09 volumio exim[1624]: 2025-10-29 09:36:09 1vDuAb-0000QC-CI Cannot open main log file "/var/log/exim4/mainlog": Permission denied: euid=118 egid=124 Oct 29 09:36:09 volumio exim[1624]: exim: could not open panic log - aborting: see message(s) above Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio CRON[783]: (volumio) MAIL (mailed 65 bytes of output but got status 0x0001 from MTA ) Oct 29 09:36:09 volumio CRON[783]: pam_unix(cron:session): session closed for user volumio Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Oct 29 09:36:09 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:09 volumio volumio[1322]: info: Upmpdcli Daemon Started Oct 29 09:36:10 volumio volumio[1322]: info: Starting Shairport Sync Oct 29 09:36:10 volumio volumio[1322]: info: Starting Shairport Sync Oct 29 09:36:10 volumio volumio[1322]: info: Starting Shairport Sync Oct 29 09:36:10 volumio sudo[1653]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 29 09:36:10 volumio sudo[1653]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 09:36:10 volumio sudo[1655]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 29 09:36:10 volumio sudo[1655]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 09:36:10 volumio volumio[1322]: info: CoreCommandRouter::volumioGetState Oct 29 09:36:10 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:10 volumio sudo[1658]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 29 09:36:10 volumio sudo[1658]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 09:36:10 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 29 09:36:10 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 29 09:36:10 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 29 09:36:10 volumio volumio[1322]: info: CoreCommandRouter::volumioGetState Oct 29 09:36:10 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:10 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 29 09:36:10 volumio sudo[1653]: pam_unix(sudo:session): session closed for user root Oct 29 09:36:10 volumio sudo[1658]: pam_unix(sudo:session): session closed for user root Oct 29 09:36:10 volumio sudo[1655]: pam_unix(sudo:session): session closed for user root Oct 29 09:36:10 volumio volumio[1322]: info: Shairport-Sync Started Oct 29 09:36:10 volumio volumio[1322]: Error adding Membership: Error: addMembership EINVAL Oct 29 09:36:10 volumio volumio[1322]: info: Shairport-Sync Started Oct 29 09:36:10 volumio volumio[1322]: info: Shairport-Sync Started Oct 29 09:36:10 volumio volumio[1322]: info: JP_Radio::getting stations Oct 29 09:36:11 volumio mpd[1597]: Oct 29 09:36 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 29 09:36:11 volumio systemd[1]: Started Music Player Daemon. Oct 29 09:36:11 volumio sudo[1567]: pam_unix(sudo:session): session closed for user root Oct 29 09:36:11 volumio sudo[1576]: pam_unix(sudo:session): session closed for user root Oct 29 09:36:11 volumio volumio[1322]: Upnp client error: Error: This socket has been ended by the other party Oct 29 09:36:11 volumio volumio[1322]: info: Completed starting Core Plugins Oct 29 09:36:11 volumio volumio[1322]: info: ------------------------------------------- Oct 29 09:36:11 volumio volumio[1322]: info: ----- MyVolumio plugins startup ---- Oct 29 09:36:11 volumio volumio[1322]: info: ------------------------------------------- Oct 29 09:36:11 volumio volumio[1322]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 29 09:36:11 volumio volumio[1322]: info: MPD running with PID1597 Oct 29 09:36:11 volumio volumio[1322]: ,establishing connection Oct 29 09:36:11 volumio volumio[1322]: error: MPD error: The expression evaluated to a falsy value: Oct 29 09:36:11 volumio volumio[1322]: assert.ok(self.idling) Oct 29 09:36:11 volumio volumio[1322]: error: The expression evaluated to a falsy value: Oct 29 09:36:11 volumio volumio[1322]: assert.ok(self.idling) Oct 29 09:36:11 volumio volumio[1322]: error: MPD error: The expression evaluated to a falsy value: Oct 29 09:36:11 volumio volumio[1322]: assert.ok(self.idling) Oct 29 09:36:11 volumio volumio[1322]: error: The expression evaluated to a falsy value: Oct 29 09:36:11 volumio volumio[1322]: assert.ok(self.idling) Oct 29 09:36:11 volumio volumio[1322]: error: updateQueue error: null Oct 29 09:36:13 volumio volumio[1622]: Generating RSA private key, 4096 bit long modulus (2 primes) Oct 29 09:36:14 volumio systemd[1]: systemd-timedated.service: Succeeded. Oct 29 09:36:15 volumio volumio[1322]: info: Oct 29 09:36:15 volumio volumio[1322]: ---------------------------- Client requests Volume 30 Oct 29 09:36:15 volumio volumio[1322]: info: VolumeController::SetAlsaVolume30 Oct 29 09:36:15 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:36:15 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:15 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:36:15 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:36:15 volumio volumio[1322]: info: JP_Radio::Updating program listings Oct 29 09:36:17 volumio volumio[1322]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 29 09:36:17 volumio volumio[1322]: info: Oct 29 09:36:17 volumio volumio[1322]: ---------------------------- Client requests Volume NaN Oct 29 09:36:17 volumio volumio[1322]: info: VolumeController::SetAlsaVolumeNaN Oct 29 09:36:17 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:36:17 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:17 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:36:17 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 29 09:36:20 volumio volumio[1322]: info: Adding plugin bluetooth to MyMusic Plugins Oct 29 09:36:20 volumio volumio[1322]: info: Adding plugin multiroom to MyMusic Plugins Oct 29 09:36:20 volumio volumio[1322]: info: Adding plugin metavolumio to MyMusic Plugins Oct 29 09:36:20 volumio volumio[1322]: info: Adding plugin cd_controller to MyMusic Plugins Oct 29 09:36:20 volumio volumio[1322]: info: Adding plugin qobuzconnect to MyMusic Plugins Oct 29 09:36:20 volumio volumio[1322]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 29 09:36:20 volumio volumio[1322]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 29 09:36:20 volumio volumio[1322]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 29 09:36:23 volumio volumio[1322]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 29 09:36:23 volumio volumio[1322]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 29 09:36:23 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:23 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:23 volumio volumio[1322]: info: Starting MyVolumio Remote Streaming Endpoints Oct 29 09:36:23 volumio volumio[1322]: info: MyVolumio login type: Token Oct 29 09:36:23 volumio volumio[1322]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 29 09:36:23 volumio volumio[1322]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 29 09:36:26 volumio volumio[1322]: info: Starting Streaming Service Transparent Proxy Oct 29 09:36:26 volumio volumio[1322]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 29 09:36:26 volumio volumio[1322]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 29 09:36:26 volumio volumio[1322]: info: Streaming services startup Oct 29 09:36:26 volumio volumio[1322]: info: Starting Streaming Daemon Oct 29 09:36:26 volumio sudo[1745]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 29 09:36:26 volumio sudo[1745]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 09:36:26 volumio volumio[1322]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 29 09:36:26 volumio sudo[1745]: pam_unix(sudo:session): session closed for user root Oct 29 09:36:27 volumio volumio[1322]: error: Cannot start Volumio Streaming Daemon Oct 29 09:36:27 volumio volumio[1322]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 29 09:36:27 volumio volumio[1322]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 29 09:36:27 volumio volumio[1322]: info: CoreCommandRouter::volumioGetState Oct 29 09:36:27 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:28 volumio volumio[1322]: error: MyVolumio Custom Token format not valid, refreshing it Oct 29 09:36:29 volumio volumio[1322]: STREAMING PROXY: Starting server on port 3245 Oct 29 09:36:29 volumio volumio[1322]: Node JS runtime: 14 Oct 29 09:36:30 volumio volumio[1322]: info: MyVolumio login type: Token Oct 29 09:36:32 volumio volumio[1322]: info: Oct 29 09:36:32 volumio volumio[1322]: ---------------------------- Client requests Volume 30 Oct 29 09:36:32 volumio volumio[1322]: info: VolumeController::SetAlsaVolume30 Oct 29 09:36:32 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:36:32 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:32 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:36:32 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:36:35 volumio volumio[1622]: ...........................................................................................................................................................................++++ Oct 29 09:36:35 volumio volumio[1322]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 29 09:36:35 volumio volumio[1322]: info: Oct 29 09:36:35 volumio volumio[1322]: ---------------------------- Client requests Volume NaN Oct 29 09:36:35 volumio volumio[1322]: info: VolumeController::SetAlsaVolumeNaN Oct 29 09:36:35 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:36:35 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:35 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:36:35 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:36:37 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 29 09:36:37 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:37 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 29 09:36:38 volumio volumio-remote-updater[737]: Test mode enabled Oct 29 09:36:38 volumio volumio-remote-updater[737]: No alpha test mode Oct 29 09:36:38 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 29 09:36:38 volumio volumio[1322]: info: MyVolumio token set successfully Oct 29 09:36:38 volumio volumio[1322]: info: MYVOLUMIO: Adding device Oct 29 09:36:38 volumio volumio[1322]: info: MYVOLUMIO: Evaluating Server Oct 29 09:36:40 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 29 09:36:40 volumio volumio[1322]: info: MyVolumio status changed Oct 29 09:36:40 volumio volumio[1322]: info: Streaming services startup Oct 29 09:36:40 volumio volumio[1322]: info: Starting Streaming Daemon Oct 29 09:36:40 volumio volumio[1322]: info: Removing browser output: myVolumio user plan is not superstar Oct 29 09:36:40 volumio volumio[1322]: info: Removing audio output: Oct 29 09:36:40 volumio volumio[1322]: info: Stoppping Tunnel 1 Oct 29 09:36:41 volumio sudo[1847]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 29 09:36:41 volumio sudo[1847]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 09:36:41 volumio sudo[1850]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 29 09:36:41 volumio sudo[1850]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 29 09:36:41 volumio sudo[1847]: pam_unix(sudo:session): session closed for user root Oct 29 09:36:41 volumio volumio[1322]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Oct 29 09:36:41 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 29 09:36:41 volumio sudo[1850]: pam_unix(sudo:session): session closed for user root Oct 29 09:36:41 volumio volumio[1322]: info: Setting Geolocation for MyVolumio to as1 Oct 29 09:36:41 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:41 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:41 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:41 volumio volumio[1322]: error: Cannot start Volumio Streaming Daemon Oct 29 09:36:41 volumio volumio[1322]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 29 09:36:41 volumio volumio[1322]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 29 09:36:41 volumio volumio[1322]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Oct 29 09:36:41 volumio volumio[1322]: info: Remote SSH Stopped Oct 29 09:36:41 volumio volumio[1322]: info: CoreCommandRouter::volumioGetState Oct 29 09:36:41 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:41 volumio ntpd[1064]: Soliciting pool server 160.16.113.133 Oct 29 09:36:41 volumio volumio[1322]: info: CoreCommandRouter::volumioGetState Oct 29 09:36:41 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:41 volumio ntpd[1064]: Soliciting pool server 162.159.200.1 Oct 29 09:36:42 volumio ntpd[1064]: Soliciting pool server 162.159.200.123 Oct 29 09:36:42 volumio ntpd[1064]: Soliciting pool server 139.162.81.45 Oct 29 09:36:43 volumio volumio[1322]: info: Updating MyVolumio device info Oct 29 09:36:43 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:43 volumio volumio[1322]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 29 09:36:43 volumio ntpd[1064]: Soliciting pool server 45.76.211.39 Oct 29 09:36:43 volumio ntpd[1064]: Soliciting pool server 151.248.68.194 Oct 29 09:36:44 volumio ntpd[1064]: Soliciting pool server 45.77.20.103 Oct 29 09:36:44 volumio ntpd[1064]: Soliciting pool server 108.160.132.224 Oct 29 09:36:44 volumio ntpd[1064]: Soliciting pool server 172.104.124.149 Oct 29 09:36:45 volumio ntpd[1064]: Soliciting pool server 153.127.202.76 Oct 29 09:36:45 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:45 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:45 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 29 09:36:45 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 29 09:36:45 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 29 09:36:45 volumio volumio[1322]: info: CoreCommandRouter::volumioGetBrowseSources Oct 29 09:36:45 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 29 09:36:45 volumio volumio[1322]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 29 09:36:45 volumio ntpd[1064]: Soliciting pool server 240b:4009:272:9c06:def8:1b59:32ba:d5f Oct 29 09:36:46 volumio ntpd[1064]: Soliciting pool server 129.250.35.250 Oct 29 09:36:47 volumio volumio[1322]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 29 09:36:47 volumio volumio[1322]: info: Completed starting MyVolumio Plugin Oct 29 09:36:47 volumio volumio[1322]: [Metrics] CommandRouter: 57s 694.49ms Oct 29 09:36:47 volumio volumio[1322]: info: CoreCommandRouter::volumiosetStartupVolume Oct 29 09:36:47 volumio ntpd[1064]: Soliciting pool server 160.25.135.55 Oct 29 09:36:47 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 29 09:36:47 volumio volumio[1322]: info: VolumeController:: Setting startup Volume 70 Oct 29 09:36:47 volumio volumio[1322]: info: VolumeController::SetAlsaVolume70 Oct 29 09:36:47 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:47 volumio volumio[1322]: info: CoreCommandRouter::Close All Modals sent Oct 29 09:36:47 volumio volumio[1322]: info: CoreCommandRouter::Close All Modals sent Oct 29 09:36:47 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:36:47 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:47 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:36:47 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:36:47 volumio volumio[1322]: info: MYVOLUMIO: Adding device Oct 29 09:36:47 volumio volumio[1322]: info: MYVOLUMIO: Evaluating Server Oct 29 09:36:47 volumio volumio[1322]: info: Oct 29 09:36:47 volumio volumio[1322]: ---------------------------- Client requests Volume 30 Oct 29 09:36:47 volumio volumio[1322]: info: VolumeController::SetAlsaVolume30 Oct 29 09:36:47 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:36:47 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:47 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:36:47 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:36:49 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 29 09:36:49 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 29 09:36:49 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 29 09:36:49 volumio volumio[1322]: info: Setting Geolocation for MyVolumio to as1 Oct 29 09:36:49 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:49 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:49 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:49 volumio volumio[1322]: info: Oct 29 09:36:49 volumio volumio[1322]: ---------------------------- Client requests Volume NaN Oct 29 09:36:49 volumio volumio[1322]: info: VolumeController::SetAlsaVolumeNaN Oct 29 09:36:49 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:36:49 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:36:49 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:36:49 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:36:50 volumio ntpd[1064]: receive: Unexpected origin timestamp 0xecabe021.5531168a does not match aorg 0000000000.00000000 from server@45.76.211.39 xmt 0xecabe022.7cff6a48 Oct 29 09:36:50 volumio ntpd[1064]: receive: Unexpected origin timestamp 0xecabe021.553cacc2 does not match aorg 0000000000.00000000 from server@162.159.200.1 xmt 0xecabe022.7cafe5aa Oct 29 09:36:50 volumio ntpd[1064]: receive: Unexpected origin timestamp 0xecabe021.553f403b does not match aorg 0000000000.00000000 from server@160.16.113.133 xmt 0xecabe022.7cf35506 Oct 29 09:36:50 volumio ntpd[1064]: receive: Unexpected origin timestamp 0xecabe021.5518673d does not match aorg 0000000000.00000000 from server@129.250.35.250 xmt 0xecabe022.7d4d488c Oct 29 09:36:51 volumio volumio[1322]: info: Updating MyVolumio device info Oct 29 09:36:51 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 29 09:36:51 volumio volumio[1322]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 29 09:36:52 volumio volumio[1322]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 29 09:36:55 volumio volumio[1322]: info: BOOT COMPLETED Oct 29 09:36:55 volumio volumio[1322]: info: CoreCommandRouter::volumioGetState Oct 29 09:36:55 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:37:01 volumio volumio[1322]: info: Oct 29 09:37:01 volumio volumio[1322]: ---------------------------- Client requests Volume 30 Oct 29 09:37:01 volumio volumio[1322]: info: VolumeController::SetAlsaVolume30 Oct 29 09:37:01 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:37:01 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:37:01 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:37:01 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:37:03 volumio volumio[1322]: info: Oct 29 09:37:03 volumio volumio[1322]: ---------------------------- Client requests Volume NaN Oct 29 09:37:03 volumio volumio[1322]: info: VolumeController::SetAlsaVolumeNaN Oct 29 09:37:03 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:37:03 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:37:03 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:37:03 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:37:09 volumio volumio[1322]: info: CoreCommandRouter::volumioGetState Oct 29 09:37:09 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:37:15 volumio volumio[1322]: info: Oct 29 09:37:15 volumio volumio[1322]: ---------------------------- Client requests Volume 30 Oct 29 09:37:15 volumio volumio[1322]: info: VolumeController::SetAlsaVolume30 Oct 29 09:37:15 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:37:15 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:37:15 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:37:15 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:37:16 volumio volumio[1622]: .............................................................................................................................................................................................................................................................................................................................++++ Oct 29 09:37:16 volumio volumio[1622]: e is 65537 (0x010001) Oct 29 09:37:16 volumio volumio[1622]: writing RSA key Oct 29 09:37:17 volumio volumio[1322]: info: Oct 29 09:37:17 volumio volumio[1322]: ---------------------------- Client requests Volume NaN Oct 29 09:37:17 volumio volumio[1322]: info: VolumeController::SetAlsaVolumeNaN Oct 29 09:37:17 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:37:17 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:37:17 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:37:17 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:37:22 volumio volumio[1322]: info: CoreCommandRouter::volumioGetState Oct 29 09:37:22 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:37:25 volumio volumio[1322]: info: JP_Radio::App is listening on port 9000. Oct 29 09:37:28 volumio volumio[1322]: info: Oct 29 09:37:28 volumio volumio[1322]: ---------------------------- Client requests Volume 30 Oct 29 09:37:28 volumio volumio[1322]: info: VolumeController::SetAlsaVolume30 Oct 29 09:37:28 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:37:28 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:37:28 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:37:28 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:37:29 volumio volumio[1322]: info: Oct 29 09:37:29 volumio volumio[1322]: ---------------------------- Client requests Volume NaN Oct 29 09:37:29 volumio volumio[1322]: info: VolumeController::SetAlsaVolumeNaN Oct 29 09:37:29 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:37:29 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:37:29 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:37:29 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:37:34 volumio volumio[1322]: info: CoreCommandRouter::volumioGetState Oct 29 09:37:34 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:37:39 volumio volumio[1322]: info: Oct 29 09:37:39 volumio volumio[1322]: ---------------------------- Client requests Volume 30 Oct 29 09:37:39 volumio volumio[1322]: info: VolumeController::SetAlsaVolume30 Oct 29 09:37:39 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:37:39 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:37:39 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:37:39 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:37:40 volumio volumio[1322]: info: Oct 29 09:37:40 volumio volumio[1322]: ---------------------------- Client requests Volume NaN Oct 29 09:37:40 volumio volumio[1322]: info: VolumeController::SetAlsaVolumeNaN Oct 29 09:37:40 volumio volumio[1322]: info: CoreStateMachine::pushState Oct 29 09:37:40 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:37:40 volumio volumio[1322]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 29 09:37:40 volumio volumio[1322]: info: CoreCommandRouter::volumioPushState Oct 29 09:37:41 volumio dhcpcd[831]: eth0: carrier lost Oct 29 09:37:41 volumio kernel: dwmac-sun8i 1c30000.ethernet eth0: Link is Down Oct 29 09:37:41 volumio avahi-daemon[759]: Withdrawing address record for 192.168.223.251 on eth0. Oct 29 09:37:41 volumio avahi-daemon[759]: Leaving mDNS multicast group on interface eth0.IPv4 with address 192.168.223.251. Oct 29 09:37:41 volumio avahi-daemon[759]: Interface eth0.IPv4 no longer relevant for mDNS. Oct 29 09:37:41 volumio volumio[1322]: info: Discovery: A device disappeared from network Oct 29 09:37:41 volumio volumio[1322]: info: Discovery: Device volumio disappeared from network Oct 29 09:37:41 volumio dhcpcd[831]: eth0: deleting route to 192.168.223.0/24 Oct 29 09:37:41 volumio dhcpcd[831]: eth0: deleting default route via 192.168.223.1 Oct 29 09:37:41 volumio ifplugd(eth0)[1027]: Link beat lost. Oct 29 09:37:43 volumio ntpd[1064]: Deleting interface #4 eth0, 192.168.223.251#123, interface stats: received=84, sent=84, dropped=0, active_time=108 secs Oct 29 09:37:43 volumio ntpd[1064]: 160.25.135.55 local addr 192.168.223.251 -> Oct 29 09:37:43 volumio ntpd[1064]: 129.250.35.250 local addr 192.168.223.251 -> Oct 29 09:37:43 volumio ntpd[1064]: 153.127.202.76 local addr 192.168.223.251 -> Oct 29 09:37:43 volumio ntpd[1064]: 172.104.124.149 local addr 192.168.223.251 -> Oct 29 09:37:43 volumio ntpd[1064]: 108.160.132.224 local addr 192.168.223.251 -> Oct 29 09:37:43 volumio ntpd[1064]: 45.77.20.103 local addr 192.168.223.251 -> Oct 29 09:37:43 volumio ntpd[1064]: 151.248.68.194 local addr 192.168.223.251 -> Oct 29 09:37:43 volumio ntpd[1064]: 45.76.211.39 local addr 192.168.223.251 -> Oct 29 09:37:43 volumio ntpd[1064]: 139.162.81.45 local addr 192.168.223.251 -> Oct 29 09:37:43 volumio ntpd[1064]: 162.159.200.123 local addr 192.168.223.251 -> Oct 29 09:37:43 volumio ntpd[1064]: 162.159.200.1 local addr 192.168.223.251 -> Oct 29 09:37:43 volumio ntpd[1064]: 160.16.113.133 local addr 192.168.223.251 -> Oct 29 09:37:43 volumio dhcpcd[831]: eth0: carrier acquired Oct 29 09:37:43 volumio kernel: dwmac-sun8i 1c30000.ethernet eth0: Link is Up - 100Mbps/Full - flow control off Oct 29 09:37:43 volumio dhcpcd[831]: eth0: IAID a2:b4:5f:98 Oct 29 09:37:43 volumio dhcpcd[831]: eth0: probing address 192.168.223.251/24 Oct 29 09:37:44 volumio dhcpcd[831]: eth0: soliciting an IPv6 router Oct 29 09:37:44 volumio ifplugd(eth0)[1027]: Link beat detected. Oct 29 09:37:45 volumio volumio[1322]: info: CoreCommandRouter::volumioGetState Oct 29 09:37:45 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:37:47 volumio volumio[1322]: info: Volumio Network Manager: Network status updated: 0 Oct 29 09:37:49 volumio dhcpcd[831]: eth0: using static address 192.168.223.251/24 Oct 29 09:37:49 volumio dhcpcd[831]: eth0: adding route to 192.168.223.0/24 Oct 29 09:37:49 volumio avahi-daemon[759]: Joining mDNS multicast group on interface eth0.IPv4 with address 192.168.223.251. Oct 29 09:37:49 volumio dhcpcd[831]: eth0: adding default route via 192.168.223.1 Oct 29 09:37:49 volumio avahi-daemon[759]: New relevant interface eth0.IPv4 for mDNS. Oct 29 09:37:49 volumio avahi-daemon[759]: Registering new address record for 192.168.223.251 on eth0.IPv4. Oct 29 09:37:50 volumio volumio[1322]: info: Discovery: adding 55e405f5-a25e-4eee-b880-50dec7a9cf3e Oct 29 09:37:50 volumio volumio[1322]: info: Discovery: Found device Volumio Oct 29 09:37:50 volumio volumio[1322]: info: CoreCommandRouter::volumioGetState Oct 29 09:37:50 volumio volumio[1322]: info: CorePlayQueue::getTrack 0 Oct 29 09:37:50 volumio volumio[1322]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 29 09:37:50 volumio volumio[1322]: Error: The value NaN is not a number Oct 29 09:37:50 volumio volumio[1322]: at Config.forceToType (/volumio/node_modules/v-conf/index.js:322:20) Oct 29 09:37:50 volumio volumio[1322]: at Config.set (/volumio/node_modules/v-conf/index.js:153:25) Oct 29 09:37:50 volumio volumio[1322]: at ControllerVolumioDiscovery.updateMultiroomDevice (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:323:25) Oct 29 09:37:50 volumio volumio[1322]: at ControllerVolumioDiscovery.connectToRemoteVolumio (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:273:10) Oct 29 09:37:50 volumio volumio[1322]: at Browser. (/volumio/app/plugins/system_controller/volumiodiscovery/index.js:192:12) Oct 29 09:37:50 volumio volumio[1322]: at Browser.emit (events.js:400:28) Oct 29 09:37:50 volumio volumio[1322]: at on_resolver_done (/volumio/node_modules/mdns/lib/browser.js:31:14) Oct 29 09:37:50 volumio volumio[1322]: at next (/volumio/node_modules/mdns/lib/browser.js:106:7) Oct 29 09:37:50 volumio volumio[1322]: at Array.makeAddressesUnique (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:177:5) Oct 29 09:37:50 volumio volumio[1322]: at next (/volumio/node_modules/mdns/lib/browser.js:109:21) Oct 29 09:37:50 volumio volumio[1322]: at /volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:160:11 Oct 29 09:37:50 volumio volumio[1322]: at getaddrinfo_complete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:108:7) Oct 29 09:37:50 volumio volumio[1322]: at GetAddrInfoReqWrap.oncomplete (/volumio/node_modules/mdns/lib/resolver_sequence_tasks.js:120:9) Oct 29 09:37:50 volumio volumio[1322]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 29 09:37:51 volumio ntpd[1064]: Listen normally on 5 eth0 192.168.223.251:123 Oct 29 09:37:51 volumio ntpd[1064]: new interface(s) found: waking up resolver Oct 29 09:37:51 volumio sudo[2205]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-10-29 09:36 Oct 29 09:37:51 volumio sudo[2205]: 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="7044262daed40f016564d0bf019f582e0bb49d71" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="fc4c820ddd3b5fc1a7a6b54ef112273ebd122010" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat 16 Aug 2025 11:55:35 AM CEST" VOLUMIO_VERSION="3.832" VOLUMIO_HARDWARE="nanopineo-armbian" VOLUMIO_DEVICENAME="NanoPi Neo" VOLUMIO_HASH="58507b464d7a6cb68ea58c3b8b4ba474"