-- Logs begin at Sat 2024-11-23 17:23:17 EET, end at Sat 2024-11-23 17:25:15 EET. -- Nov 23 17:24:38 volumio-aph systemd-timedated[1002]: Changed local time to Sat Nov 23 17:24:38 2024 Nov 23 17:24:38 volumio-aph sudo[1000]: pam_unix(sudo:session): session closed for user root Nov 23 17:24:38 volumio-aph volumio-time-update[534]: volumio-time-update-util: System time updated successfully. Nov 23 17:24:38 volumio-aph systemd[1]: Started Volumio Time Update Utility. Nov 23 17:24:38 volumio-aph volumio[835]: info: Loading plugin "alarm-clock"... Nov 23 17:24:38 volumio-aph volumio[835]: info: Loading plugin "airplay_emulation"... Nov 23 17:24:38 volumio-aph volumio[835]: info: Starting Shairport Sync Nov 23 17:24:38 volumio-aph volumio[835]: info: Loading plugin "last_100"... Nov 23 17:24:38 volumio-aph ntpd[916]: Soliciting pool server 212.59.0.1 Nov 23 17:24:38 volumio-aph volumio[835]: info: Loading plugin "webradio"... Nov 23 17:24:38 volumio-aph volumio[835]: info: Loading plugin "i2s_dacs"... Nov 23 17:24:38 volumio-aph volumio[835]: info: Loading plugin "volumiodiscovery"... Nov 23 17:24:38 volumio-aph volumio[835]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 23 17:24:38 volumio-aph volumio[835]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 23 17:24:38 volumio-aph volumio[835]: *** WARNING *** For more information see Nov 23 17:24:38 volumio-aph volumio[835]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 23 17:24:38 volumio-aph node[835]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Nov 23 17:24:38 volumio-aph volumio[835]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 23 17:24:38 volumio-aph volumio[835]: *** WARNING *** For more information see Nov 23 17:24:38 volumio-aph node[835]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 23 17:24:38 volumio-aph node[835]: *** WARNING *** For more information see Nov 23 17:24:38 volumio-aph node[835]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Nov 23 17:24:38 volumio-aph node[835]: *** WARNING *** Please fix your application to use the native API of Avahi! Nov 23 17:24:38 volumio-aph node[835]: *** WARNING *** For more information see Nov 23 17:24:38 volumio-aph volumio[835]: info: Applying required configuration parameters for plugin volumiodiscovery Nov 23 17:24:39 volumio-aph volumio[835]: info: Discovery: Started advertising with name: Volumio-aph Nov 23 17:24:39 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 23 17:24:39 volumio-aph volumio[835]: info: Loading plugin "spop"... Nov 23 17:24:39 volumio-aph ntpd[916]: Soliciting pool server 88.222.88.11 Nov 23 17:24:39 volumio-aph volumio-remote-updater[525]: [2024-11-23 17:24:39] [connect] Successful connection Nov 23 17:24:39 volumio-aph ntpd[916]: Soliciting pool server 212.59.0.2 Nov 23 17:24:39 volumio-aph nmbd[787]: [2024/11/23 17:24:39.919766, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 23 17:24:39 volumio-aph nmbd[787]: daemon_ready: STATUS=daemon 'nmbd' finished starting up and ready to serve connections Nov 23 17:24:39 volumio-aph systemd[1]: Started Samba NMB Daemon. Nov 23 17:24:39 volumio-aph systemd[1]: Starting Samba Winbind Daemon... Nov 23 17:24:40 volumio-aph winbindd[1005]: [2024/11/23 17:24:40.324251, 0] ../source3/winbindd/winbindd_cache.c:3160(initialize_winbindd_cache) Nov 23 17:24:40 volumio-aph winbindd[1005]: initialize_winbindd_cache: clearing cache and re-creating with version number 2 Nov 23 17:24:40 volumio-aph winbindd[1005]: [2024/11/23 17:24:40.346278, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 23 17:24:40 volumio-aph systemd[1]: Started Samba Winbind Daemon. Nov 23 17:24:40 volumio-aph winbindd[1005]: daemon_ready: STATUS=daemon 'winbindd' finished starting up and ready to serve connections Nov 23 17:24:40 volumio-aph systemd[1]: Starting Samba SMB Daemon... Nov 23 17:24:40 volumio-aph ntpd[916]: Soliciting pool server 165.227.160.4 Nov 23 17:24:40 volumio-aph ntpd[916]: Soliciting pool server 185.177.150.95 Nov 23 17:24:40 volumio-aph volumio[835]: info: Loading plugin "autostart"... Nov 23 17:24:41 volumio-aph smbd[1010]: [2024/11/23 17:24:41.006233, 0] ../lib/util/become_daemon.c:138(daemon_ready) Nov 23 17:24:41 volumio-aph systemd[1]: Started Samba SMB Daemon. Nov 23 17:24:41 volumio-aph smbd[1010]: daemon_ready: STATUS=daemon 'smbd' finished starting up and ready to serve connections Nov 23 17:24:41 volumio-aph systemd[1]: Reached target Multi-User System. Nov 23 17:24:41 volumio-aph systemd[1]: Reached target Graphical Interface. Nov 23 17:24:41 volumio-aph systemd[1]: Starting Update UTMP about System Runlevel Changes... Nov 23 17:24:41 volumio-aph systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Nov 23 17:24:41 volumio-aph systemd[1]: Started Update UTMP about System Runlevel Changes. Nov 23 17:24:41 volumio-aph systemd[1]: Startup finished in 15.860s (kernel) + 23.079s (userspace) = 38.939s. Nov 23 17:24:41 volumio-aph volumio[835]: info: Applying required configuration parameters for plugin autostart Nov 23 17:24:41 volumio-aph volumio[835]: info: AutoStart - onVolumioStart - read config.json Nov 23 17:24:41 volumio-aph volumio[835]: info: Loading plugin "outputs"... Nov 23 17:24:41 volumio-aph volumio[835]: info: Loading plugin "albumart"... Nov 23 17:24:41 volumio-aph volumio[835]: info: Plugin example_plugin is not enabled Nov 23 17:24:41 volumio-aph volumio[835]: info: Loading plugin "inputs"... Nov 23 17:24:41 volumio-aph volumio[835]: info: Loading plugin "updater_comm"... Nov 23 17:24:41 volumio-aph volumio[835]: info: Plugin mpdemulation is not enabled Nov 23 17:24:41 volumio-aph volumio[835]: info: Loading plugin "rest_api"... Nov 23 17:24:41 volumio-aph volumio[835]: info: Loading plugin "websocket"... Nov 23 17:24:41 volumio-aph ntpd[916]: Soliciting pool server 78.58.99.133 Nov 23 17:24:41 volumio-aph ntpd[916]: Soliciting pool server 2a03:b0c0:3:d0::d72:8001 Nov 23 17:24:41 volumio-aph volumio[835]: info: Starting Socket.io Server version 2.3.0 Nov 23 17:24:41 volumio-aph volumio[835]: info: Loading plugin "audiophonicsonoff"... Nov 23 17:24:41 volumio-aph volumio[835]: Forking 3 albumart workers Nov 23 17:24:42 volumio-aph volumio[835]: info: Applying required configuration parameters for plugin audiophonicsonoff Nov 23 17:24:42 volumio-aph volumio[835]: info: Audiophonics on/off initiated Nov 23 17:24:42 volumio-aph volumio[835]: info: Loading plugin "backup_restore"... Nov 23 17:24:42 volumio-aph volumio[835]: info: Applying required configuration parameters for plugin backup_restore Nov 23 17:24:42 volumio-aph volumio[835]: info: Loading i18n strings for locale en Nov 23 17:24:42 volumio-aph volumio[835]: Updating browse sources language Nov 23 17:24:42 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 17:24:42 volumio-aph volumio[835]: Starting albumart workers Nov 23 17:24:42 volumio-aph volumio[835]: Starting albumart workers Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::initPlayerControls Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 23 17:24:43 volumio-aph volumio[835]: Express server listening on port 3000 Nov 23 17:24:43 volumio-aph volumio[835]: [Metrics] WebUI: 10s 427.01ms Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreStateMachine::resetVolumioState Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreStateMachine::getcurrentVolume Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::volumioRetrievevolume Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:24:43 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:24:43 volumio-aph volumio[835]: Starting albumart workers Nov 23 17:24:43 volumio-aph volumio[835]: info: Volumio Network Manager: Network status updated: 1 Nov 23 17:24:43 volumio-aph volumio[835]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Nov 23 17:24:43 volumio-aph volumio[835]: wlan0 Interface doesn't support scanning. Nov 23 17:24:43 volumio-aph volumio[835]: info: Cannot use regular scanning, forcing with ap-force Nov 23 17:24:43 volumio-aph sudo[1052]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Nov 23 17:24:43 volumio-aph sudo[1052]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:24:43 volumio-aph sudo[1052]: pam_unix(sudo:session): session closed for user root Nov 23 17:24:43 volumio-aph volumio[835]: command failed: No such device (-19) Nov 23 17:24:43 volumio-aph volumio[835]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Nov 23 17:24:43 volumio-aph volumio[835]: command failed: No such device (-19) Nov 23 17:24:43 volumio-aph volumio[835]: verbose: New Socket.io Connection to 192.168.1.218 from 192.168.1.146 UA: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:132.0) Gecko/20100101 Firefox/132.0 Engine version: 3 Transport: polling Total Clients: 1 Nov 23 17:24:43 volumio-aph volumio[835]: verbose: New Socket.io Connection to 192.168.1.218 from 192.168.1.146 UA: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:132.0) Gecko/20100101 Firefox/132.0 Engine version: 3 Transport: polling Total Clients: 2 Nov 23 17:24:43 volumio-aph volumio-remote-updater[525]: [2024-11-23 17:24:43] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1732375479 101 Nov 23 17:24:43 volumio-aph volumio[835]: 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: 3 Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 17:24:43 volumio-aph volumio[835]: info: Reloading queue from file Nov 23 17:24:43 volumio-aph volumio[835]: info: Setting Device type: Raspberry PI Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreStateMachine::setRepeat null single undefined Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:24:43 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreStateMachine::setRandom null Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:24:43 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:24:43 volumio-aph volumio[835]: info: Completed loading Core Plugins Nov 23 17:24:43 volumio-aph volumio[835]: info: Preparing to generate the ALSA configuration file Nov 23 17:24:43 volumio-aph volumio[835]: info: Asound.conf file unchanged, so no further update is needed Nov 23 17:24:43 volumio-aph volumio[835]: info: Output device has changed, restarting MPD Nov 23 17:24:43 volumio-aph volumio[835]: info: Output device has changed, restarting Shairport Sync Nov 23 17:24:43 volumio-aph sudo[1073]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:43 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 17:24:43 volumio-aph sudo[1073]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:24:43 volumio-aph sudo[1073]: pam_unix(sudo:session): session closed for user root Nov 23 17:24:43 volumio-aph sudo[1079]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 23 17:24:43 volumio-aph sudo[1079]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:24:43 volumio-aph systemd[1]: Stopping Music Player Daemon... Nov 23 17:24:43 volumio-aph volumio[835]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 23 17:24:43 volumio-aph volumio[835]: info: ___________ START PLUGINS ___________ Nov 23 17:24:43 volumio-aph volumio[835]: info: ControllerMpd::onStart: Initializing MPD Nov 23 17:24:43 volumio-aph volumio[835]: info: Creating MPD Configuration file Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 23 17:24:44 volumio-aph volumio[835]: info: [1732375484013] CoreMusicLibrary::Adding element Media Servers Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 17:24:44 volumio-aph sudo[1092]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 23 17:24:44 volumio-aph sudo[1090]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 23 17:24:44 volumio-aph sudo[1092]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:24:44 volumio-aph sudo[1090]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:24:44 volumio-aph sudo[1090]: pam_unix(sudo:session): session closed for user root Nov 23 17:24:44 volumio-aph systemd[1]: mpd.service: Succeeded. Nov 23 17:24:44 volumio-aph volumio[835]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 23 17:24:44 volumio-aph systemd[1]: Stopped Music Player Daemon. Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 17:24:44 volumio-aph systemd[1]: Starting Music Player Daemon... Nov 23 17:24:44 volumio-aph systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Nov 23 17:24:44 volumio-aph systemd[1]: mpd.service: Succeeded. Nov 23 17:24:44 volumio-aph systemd[1]: Stopped Music Player Daemon. Nov 23 17:24:44 volumio-aph volumio[835]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 23 17:24:44 volumio-aph systemd[1]: Starting Music Player Daemon... Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 23 17:24:44 volumio-aph volumio[835]: info: [1732375484183] CoreMusicLibrary::Adding element Last_100 Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 23 17:24:44 volumio-aph volumio[835]: info: [1732375484189] CoreMusicLibrary::Adding element Webradio Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 23 17:24:44 volumio-aph volumio[835]: info: Initializing BBC Radios Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: Creating Spotify config file Nov 23 17:24:44 volumio-aph sudo[1106]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 23 17:24:44 volumio-aph sudo[1106]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:24:44 volumio-aph sudo[1106]: pam_unix(sudo:session): session closed for user root Nov 23 17:24:44 volumio-aph volumio[835]: info: AutoStart - onStart Nov 23 17:24:44 volumio-aph volumio[835]: info: Configuring GPIO pins Nov 23 17:24:44 volumio-aph volumio[835]: error: Plugin audiophonicsonoff failed to start! Error: EINVAL: invalid argument, write Nov 23 17:24:44 volumio-aph volumio[835]: info: Volumio Calling Home Nov 23 17:24:44 volumio-aph kernel: export_store: invalid GPIO 4 Nov 23 17:24:44 volumio-aph volumio[835]: info: Discovery: adding 5980015e-8071-4ce4-b9f8-1ba48df83d25 Nov 23 17:24:44 volumio-aph volumio[835]: info: Discovery: Found device Volumio-aph Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::volumioGetState Nov 23 17:24:44 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:44 volumio-aph volumio[835]: info: MPD Permissions set Nov 23 17:24:44 volumio-aph volumio[835]: info: MPD Permissions set Nov 23 17:24:44 volumio-aph volumio[835]: info: Volumio called home Nov 23 17:24:44 volumio-aph volumio[835]: info: Spotify config file written Nov 23 17:24:44 volumio-aph volumio[835]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Nov 23 17:24:44 volumio-aph sudo[1127]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 23 17:24:44 volumio-aph sudo[1127]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 17:24:44 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 23 17:24:44 volumio-aph systemd[1]: Started go-librespot Daemon. Nov 23 17:24:44 volumio-aph go-librespot[1133]: Librespot-go daemon starting... Nov 23 17:24:44 volumio-aph sudo[1127]: pam_unix(sudo:session): session closed for user root Nov 23 17:24:44 volumio-aph volumio[835]: verbose: New Socket.io Connection to 192.168.1.218 from 192.168.1.146 UA: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:132.0) Gecko/20100101 Firefox/132.0 Engine version: 3 Transport: polling Total Clients: 5 Nov 23 17:24:44 volumio-aph volumio[835]: info: Starting Shairport Sync Nov 23 17:24:44 volumio-aph volumio[835]: info: Starting Shairport Sync Nov 23 17:24:44 volumio-aph volumio[835]: info: Starting Shairport Sync Nov 23 17:24:44 volumio-aph sudo[1140]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 23 17:24:44 volumio-aph sudo[1140]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:24:45 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 23 17:24:45 volumio-aph sudo[1142]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 23 17:24:45 volumio-aph sudo[1142]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:24:45 volumio-aph volumio[835]: info: CoreCommandRouter::volumioGetState Nov 23 17:24:45 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:45 volumio-aph systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 23 17:24:45 volumio-aph systemd[1]: shairport-sync.service: Succeeded. Nov 23 17:24:45 volumio-aph sudo[1145]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 23 17:24:45 volumio-aph sudo[1145]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:24:45 volumio-aph systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 23 17:24:45 volumio-aph volumio[835]: info: CoreCommandRouter::volumioGetVisibleSources Nov 23 17:24:45 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 17:24:45 volumio-aph volumio[835]: info: CoreCommandRouter::volumioGetState Nov 23 17:24:45 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:45 volumio-aph volumio[835]: info: CoreCommandRouter::volumioGetState Nov 23 17:24:45 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:45 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 23 17:24:45 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 23 17:24:45 volumio-aph volumio[835]: info: Received Get System Info Nov 23 17:24:45 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 23 17:24:45 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 23 17:24:45 volumio-aph volumio[835]: info: Discovery: Getting this device information Nov 23 17:24:45 volumio-aph volumio[835]: info: CoreCommandRouter::volumioGetState Nov 23 17:24:45 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:45 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 23 17:24:45 volumio-aph volumio[835]: info: CoreCommandRouter::volumioGetState Nov 23 17:24:45 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:45 volumio-aph volumio[835]: info: Listing playlists Nov 23 17:24:45 volumio-aph systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 23 17:24:45 volumio-aph sudo[1140]: pam_unix(sudo:session): session closed for user root Nov 23 17:24:45 volumio-aph systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 23 17:24:45 volumio-aph systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Nov 23 17:24:45 volumio-aph systemd[1]: shairport-sync.service: Succeeded. Nov 23 17:24:45 volumio-aph systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 23 17:24:45 volumio-aph systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 23 17:24:45 volumio-aph sudo[1142]: pam_unix(sudo:session): session closed for user root Nov 23 17:24:45 volumio-aph sudo[1145]: pam_unix(sudo:session): session closed for user root Nov 23 17:24:45 volumio-aph volumio[835]: info: Shairport-Sync Started Nov 23 17:24:45 volumio-aph volumio[835]: Error adding Membership: Error: addMembership EINVAL Nov 23 17:24:45 volumio-aph volumio[835]: info: Shairport-Sync Started Nov 23 17:24:45 volumio-aph volumio[835]: info: Shairport-Sync Started Nov 23 17:24:45 volumio-aph volumio[835]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 23 17:24:45 volumio-aph volumio[835]: SPOTIFY: BQBiuXt5-jZVok9kUm61ca_fnMzLS8KVL51pm3qva2wjh-HFU3at6TV2HK4LwpoyZWAB6UaFzB9BPE2rzqWJGHkfyXBCVmW2K4Lj9lMoMBCCimGvCsWgcOUZWvlRpV3rdiXdZ8TJZMlRfepNZVGmvLoMjGkkaRYQ_f-tZZcVl292hAWVqyXD0SWLANyIaeVLkpa5aok3iCOUvvCprtLM9mBl8OII_kbGbv46-_chKBA7kSPirZunRsTB9AomQaUvH64zbxsE3FiuQS4 Nov 23 17:24:45 volumio-aph volumio[835]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 23 17:24:45 volumio-aph volumio[835]: info: New Spotify access token = BQBiuXt5-jZVok9kUm61ca_fnMzLS8KVL51pm3qva2wjh-HFU3at6TV2HK4LwpoyZWAB6UaFzB9BPE2rzqWJGHkfyXBCVmW2K4Lj9lMoMBCCimGvCsWgcOUZWvlRpV3rdiXdZ8TJZMlRfepNZVGmvLoMjGkkaRYQ_f-tZZcVl292hAWVqyXD0SWLANyIaeVLkpa5aok3iCOUvvCprtLM9mBl8OII_kbGbv46-_chKBA7kSPirZunRsTB9AomQaUvH64zbxsE3FiuQS4 Nov 23 17:24:45 volumio-aph volumio[835]: info: Spotify credentials grant success - running version from March 24, 2019 Nov 23 17:24:45 volumio-aph volumio[835]: SPOTIFY: User informations: {"country":"LT","display_name":"Saulius","email":"s.cebatorius@gmail.com","explicit_content":{"filter_enabled":true,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/c9mscxz5wa4xr7u2pjao22dfx"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/c9mscxz5wa4xr7u2pjao22dfx","id":"c9mscxz5wa4xr7u2pjao22dfx","images":[],"product":"premium","type":"user","uri":"spotify:user:c9mscxz5wa4xr7u2pjao22dfx"} Nov 23 17:24:45 volumio-aph volumio[835]: info: Spotify Successfully logged in Nov 23 17:24:45 volumio-aph volumio[835]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 23 17:24:45 volumio-aph volumio[835]: info: [1732375485637] CoreMusicLibrary::Adding element Spotify Nov 23 17:24:45 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 23 17:24:45 volumio-aph volumio[835]: Cannot find translation for source Spotify Nov 23 17:24:46 volumio-aph mpd[1122]: Nov 23 17:24 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 23 17:24:47 volumio-aph ntpd[916]: receive: Unexpected origin timestamp 0xeaec723e.ad910b1b does not match aorg 0000000000.00000000 from server@212.59.0.1 xmt 0xeaec723f.858d67c2 Nov 23 17:24:47 volumio-aph ntpd[916]: receive: Unexpected origin timestamp 0xeaec723e.ad8d788b does not match aorg 0000000000.00000000 from server@212.59.0.2 xmt 0xeaec723f.85c1b3ac Nov 23 17:24:47 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:47+02:00" level=info msg="generated new device id: 2bb9fbcaec03511a186b33095b1fbbc65909a5a0" Nov 23 17:24:47 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:47+02:00" level=debug msg="stored credentials found for c9mscxz5wa4xr7u2pjao22dfx" Nov 23 17:24:47 volumio-aph systemd[1]: Started Music Player Daemon. Nov 23 17:24:47 volumio-aph sudo[1079]: pam_unix(sudo:session): session closed for user root Nov 23 17:24:47 volumio-aph sudo[1092]: pam_unix(sudo:session): session closed for user root Nov 23 17:24:47 volumio-aph volumio[835]: info: Completed starting Core Plugins Nov 23 17:24:47 volumio-aph volumio[835]: info: ------------------------------------------- Nov 23 17:24:47 volumio-aph volumio[835]: info: ----- MyVolumio plugins startup ---- Nov 23 17:24:47 volumio-aph volumio[835]: info: ------------------------------------------- Nov 23 17:24:47 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Fetching plans data.... Nov 23 17:24:47 volumio-aph volumio[835]: error: MPD error: The expression evaluated to a falsy value: Nov 23 17:24:47 volumio-aph volumio[835]: assert.ok(self.idling) Nov 23 17:24:47 volumio-aph volumio[835]: error: The expression evaluated to a falsy value: Nov 23 17:24:47 volumio-aph volumio[835]: assert.ok(self.idling) Nov 23 17:24:47 volumio-aph volumio[835]: info: MPD running with PID1122 Nov 23 17:24:47 volumio-aph volumio[835]: ,establishing connection Nov 23 17:24:47 volumio-aph volumio[835]: error: updateQueue error: null Nov 23 17:24:47 volumio-aph volumio[835]: error: updateQueue error: null Nov 23 17:24:47 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:47+02:00" level=debug msg="obtained new client token: AABhUa+tGSbP3CsjKc9vyzZF+hl1QrEiOApyKPlbvji/4arKuDt6BQRViPPtyPcTdbzMYB9CTWcUA3+5GxTCfBXlO+wAYNB9C8xViwcDlSqUUDdl6SKeXTvuD6vnxZw2dBjMsLcSDFKawdA8sMhHJPnVMu2HwnwmR6NZDhy9I/Ju3XB8rYaFl8RlumwiLz4KwtUMHJv7HsC0I2+ZpDpah+nVP5Pc9XS8NRMGXESI20RVqzSBgD5QV36Kqw6M5Q==" Nov 23 17:24:48 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:48+02:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Nov 23 17:24:48 volumio-aph sudo[1180]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 23 17:24:48 volumio-aph sudo[1180]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:24:48 volumio-aph sudo[1180]: pam_unix(sudo:session): session closed for user root Nov 23 17:24:48 volumio-aph sudo[1182]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 23 17:24:48 volumio-aph sudo[1182]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:24:48 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:48+02:00" level=debug msg="completed keyexchange" Nov 23 17:24:48 volumio-aph sudo[1186]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Nov 23 17:24:48 volumio-aph sudo[1186]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:24:48 volumio-aph sudo[1182]: pam_unix(sudo:session): session closed for user root Nov 23 17:24:48 volumio-aph systemd[1]: Started UPnP Renderer front-end to MPD. Nov 23 17:24:48 volumio-aph sudo[1186]: pam_unix(sudo:session): session closed for user root Nov 23 17:24:48 volumio-aph volumio[835]: info: Upmpdcli Daemon Started Nov 23 17:24:48 volumio-aph volumio[1190]: Generating RSA private key, 4096 bit long modulus (2 primes) Nov 23 17:24:48 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:48+02:00" level=debug msg="completed challenge" Nov 23 17:24:48 volumio-aph volumio[835]: info: go-librespot daemon successfully initialized Nov 23 17:24:48 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:48+02:00" level=debug msg="authenticated as c9mscxz5wa4xr7u2pjao22dfx" Nov 23 17:24:48 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:48+02:00" level=debug msg="authenticated as c9mscxz5wa4xr7u2pjao22dfx" Nov 23 17:24:49 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:49+02:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 23 17:24:49 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:49+02:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 23 17:24:49 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:49+02:00" level=debug msg="dealer connection opened" Nov 23 17:24:49 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:49+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Nov 23 17:24:49 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:49+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Nov 23 17:24:49 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:49+02:00" level=debug msg="received connection id: YmY3ZDMyOTMtNzZhZS00ZDcwLTgzZDItNjA3M2RlMDg2MzJkK2RlYWxlcit0Y3A6Ly8wYWNhNDE5Zi5pcC5nZXcxLnNwb3RpZnkubmV0OjU3MDArMDlBNUEyRjU3NUVBQjA3NjcyRDJERjdENEFDRjU0MjgyQ0E1NTBBMkVENzRFQTRBMDQ4Q0M1QjdGRUIxNDQzMA==" Nov 23 17:24:49 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:49+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Nov 23 17:24:49 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:49+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Nov 23 17:24:49 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:49+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Nov 23 17:24:49 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:49+02:00" level=debug msg="put connect state because NEW_DEVICE" Nov 23 17:24:49 volumio-aph volumio[1190]: .........++++ Nov 23 17:24:50 volumio-aph kernel: mmc1: error -22 whilst initialising SDIO card Nov 23 17:24:50 volumio-aph kernel: mmc1: queuing unknown CIS tuple 0x01 [8c cc 5e 98 f5 8c 32 02 c2 c2 5d 00 9d 88 5a 3a 04 08 43 03 a5 a0 32 02 42 c2 38 42 d6 02 32 02 42 c2 32 02 42 c2 32 02 42 c2 32 02 42 c2 40 00 9e 02 32 02 42 42 32 02 42 c2 32 02 c2 c2 32 02] (68 bytes) Nov 23 17:24:50 volumio-aph kernel: mmc1: queuing unknown CIS tuple 0xc2 [b2 02 42 c2 32 02 42 c2 32 02 42 42 32 02 42 42 32 02 42 42 32 02 42 c2 32 02 42 c2 32 02 42 c2 32 02 42 c2 32 02 42 c2 32 02 42 42 32 02 42 42 32 02 42 42 32 02 42 42 32 02 42 c2 67 20 b5 92] (194 bytes) Nov 23 17:24:50 volumio-aph kernel: mmc1: queuing unknown CIS tuple 0xe3 [1a 58 e0 49 32 02 42 42 3d 2c 80 f8 b2 02 c2 c2 26 64 b1 86 6c 06 81 91 b5 44 80 84 f7 48 88 ca f4 b8 d2 ad 32 02 c2 c2 49 25 ac a5 32 02 c2 c2 0f 9e 92 ea aa 06 d0 a5 63 0c e8 a2 f5 23 dd ba] (137 bytes) Nov 23 17:24:51 volumio-aph volumio[835]: info: Initializing connection to go-librespot Websocket Nov 23 17:24:51 volumio-aph go-librespot[1133]: time="2024-11-23T17:24:51+02:00" level=debug msg="new websocket client" Nov 23 17:24:51 volumio-aph volumio[835]: info: Connection to go-librespot Websocket established Nov 23 17:24:52 volumio-aph volumio[835]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Nov 23 17:24:53 volumio-aph systemd[1]: systemd-fsckd.service: Succeeded. Nov 23 17:24:55 volumio-aph volumio[835]: info: Getting Spotify volume Nov 23 17:24:55 volumio-aph volumio[835]: info: AutoStart - Plugin is starting Nov 23 17:24:55 volumio-aph volumio[835]: info: CoreCommandRouter::volumioGetQueue Nov 23 17:24:55 volumio-aph volumio[835]: info: CoreStateMachine::getQueue Nov 23 17:24:55 volumio-aph volumio[835]: info: CorePlayQueue::getQueue Nov 23 17:24:55 volumio-aph volumio[835]: info: AutoStart - start playing Nov 23 17:24:55 volumio-aph volumio[835]: info: AutoStart - start playing with no specific position Nov 23 17:24:55 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPlay Nov 23 17:24:55 volumio-aph volumio[835]: info: CoreStateMachine::play index 0 Nov 23 17:24:55 volumio-aph volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 23 17:24:55 volumio-aph volumio[835]: info: CoreStateMachine::stop Nov 23 17:24:55 volumio-aph volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 23 17:24:55 volumio-aph volumio[835]: info: CoreStateMachine::play index undefined Nov 23 17:24:55 volumio-aph volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 23 17:24:55 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:55 volumio-aph volumio[835]: info: CoreStateMachine::startPlaybackTimer Nov 23 17:24:55 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:55 volumio-aph volumio[835]: info: [1732375495324] ControllerWebradio::clearAddPlayTrack Nov 23 17:24:55 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand stop Nov 23 17:24:55 volumio-aph volumio[835]: info: Spotify volume: 100 Nov 23 17:24:55 volumio-aph volumio[835]: info: sendMpdCommand stop took 27 milliseconds Nov 23 17:24:55 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand clear Nov 23 17:24:55 volumio-aph volumio[835]: info: Nov 23 17:24:55 volumio-aph volumio[835]: ---------------------------- MPD announces system playlist update Nov 23 17:24:55 volumio-aph volumio[835]: info: Ignoring MPD Status Update Nov 23 17:24:55 volumio-aph volumio[835]: info: sendMpdCommand clear took 7 milliseconds Nov 23 17:24:55 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand load "http://radio.m-1.fm:80/m1plius/mp3" Nov 23 17:24:55 volumio-aph volumio[835]: info: Nov 23 17:24:55 volumio-aph volumio[835]: ---------------------------- MPD announces system playlist update Nov 23 17:24:55 volumio-aph volumio[835]: info: Ignoring MPD Status Update Nov 23 17:24:55 volumio-aph volumio[835]: info: Nov 23 17:24:55 volumio-aph volumio[835]: ---------------------------- MPD announces system playlist update Nov 23 17:24:55 volumio-aph volumio[835]: info: Ignoring MPD Status Update Nov 23 17:24:55 volumio-aph volumio[835]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Nov 23 17:24:55 volumio-aph volumio[835]: error: updateQueue error: null Nov 23 17:24:55 volumio-aph volumio[835]: info: ------------------------------ 59ms Nov 23 17:24:55 volumio-aph volumio[835]: info: CoreCommandRouter::volumioGetState Nov 23 17:24:55 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Nov 23 17:24:56 volumio-aph volumio[835]: info: Adding plugin bluetooth to MyMusic Plugins Nov 23 17:24:56 volumio-aph volumio[835]: info: Adding plugin multiroom to MyMusic Plugins Nov 23 17:24:56 volumio-aph volumio[835]: info: Adding plugin metavolumio to MyMusic Plugins Nov 23 17:24:56 volumio-aph volumio[835]: info: Adding plugin cd_controller to MyMusic Plugins Nov 23 17:24:56 volumio-aph volumio[835]: info: Adding plugin smart_inputs to MyMusic Plugins Nov 23 17:24:56 volumio-aph volumio[835]: info: Adding plugin tidalconnect to MyMusic Plugins Nov 23 17:24:56 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Nov 23 17:24:57 volumio-aph volumio[835]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Nov 23 17:24:57 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Nov 23 17:24:57 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 17:24:57 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 17:24:57 volumio-aph volumio[835]: info: Starting MyVolumio Remote Streaming Endpoints Nov 23 17:24:57 volumio-aph volumio[835]: info: MyVolumio login type: Token Nov 23 17:24:57 volumio-aph volumio[835]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Nov 23 17:24:57 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Nov 23 17:24:59 volumio-aph volumio[835]: info: Starting Streaming Service Transparent Proxy Nov 23 17:24:59 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Nov 23 17:24:59 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Nov 23 17:24:59 volumio-aph volumio[835]: info: Streaming services startup Nov 23 17:24:59 volumio-aph volumio[835]: info: Starting Streaming Daemon Nov 23 17:24:59 volumio-aph sudo[1231]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 23 17:24:59 volumio-aph sudo[1231]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:24:59 volumio-aph sudo[1231]: pam_unix(sudo:session): session closed for user root Nov 23 17:24:59 volumio-aph volumio[835]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Nov 23 17:24:59 volumio-aph volumio[835]: error: updateQueue error: null Nov 23 17:24:59 volumio-aph volumio[835]: error: updateQueue error: null Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand add "http://radio.m-1.fm:80/m1plius/mp3" Nov 23 17:24:59 volumio-aph volumio[835]: info: ------------------------------ 3975ms Nov 23 17:24:59 volumio-aph volumio[835]: info: ------------------------------ 3973ms Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::volumioGetState Nov 23 17:24:59 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:59 volumio-aph volumio[835]: error: Cannot start Volumio Streaming Daemon Nov 23 17:24:59 volumio-aph volumio[835]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 23 17:24:59 volumio-aph volumio[835]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 23 17:24:59 volumio-aph volumio[835]: info: Nov 23 17:24:59 volumio-aph volumio[835]: ---------------------------- MPD announces system playlist update Nov 23 17:24:59 volumio-aph volumio[835]: info: Ignoring MPD Status Update Nov 23 17:24:59 volumio-aph volumio[835]: info: sendMpdCommand add "http://radio.m-1.fm:80/m1plius/mp3" took 106 milliseconds Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand play Nov 23 17:24:59 volumio-aph volumio[835]: info: Nov 23 17:24:59 volumio-aph volumio[835]: ---------------------------- MPD announces system playlist update Nov 23 17:24:59 volumio-aph volumio[835]: info: Ignoring MPD Status Update Nov 23 17:24:59 volumio-aph volumio[835]: info: Nov 23 17:24:59 volumio-aph volumio[835]: ---------------------------- MPD announces system playlist update Nov 23 17:24:59 volumio-aph volumio[835]: info: Ignoring MPD Status Update Nov 23 17:24:59 volumio-aph volumio[835]: info: ------------------------------ 37ms Nov 23 17:24:59 volumio-aph volumio[835]: info: sendMpdCommand play took 34 milliseconds Nov 23 17:24:59 volumio-aph volumio[835]: info: ------------------------------ 25ms Nov 23 17:24:59 volumio-aph volumio[835]: info: ------------------------------ 23ms Nov 23 17:24:59 volumio-aph volumio[835]: Upnp client error: Error: This socket has been ended by the other party Nov 23 17:24:59 volumio-aph volumio[835]: info: Nov 23 17:24:59 volumio-aph volumio[835]: ---------------------------- MPD announces state update: player Nov 23 17:24:59 volumio-aph volumio[835]: info: ControllerMpd::getState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand status Nov 23 17:24:59 volumio-aph volumio[835]: info: Nov 23 17:24:59 volumio-aph volumio[835]: ---------------------------- MPD announces state update: player Nov 23 17:24:59 volumio-aph volumio[835]: info: ControllerMpd::getState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand status Nov 23 17:24:59 volumio-aph volumio[835]: info: Nov 23 17:24:59 volumio-aph volumio[835]: ---------------------------- MPD announces state update: player Nov 23 17:24:59 volumio-aph volumio[835]: info: ControllerMpd::getState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand status Nov 23 17:24:59 volumio-aph volumio[835]: info: Nov 23 17:24:59 volumio-aph volumio[835]: ---------------------------- MPD announces state update: player Nov 23 17:24:59 volumio-aph volumio[835]: info: Nov 23 17:24:59 volumio-aph volumio[835]: ---------------------------- MPD announces system playlist update Nov 23 17:24:59 volumio-aph volumio[835]: info: Ignoring MPD Status Update Nov 23 17:24:59 volumio-aph volumio[835]: info: Nov 23 17:24:59 volumio-aph volumio[835]: ---------------------------- MPD announces state update: player Nov 23 17:24:59 volumio-aph volumio[835]: info: sendMpdCommand status took 55 milliseconds Nov 23 17:24:59 volumio-aph volumio[835]: info: ControllerMpd::getState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand status Nov 23 17:24:59 volumio-aph volumio[835]: info: sendMpdCommand status took 49 milliseconds Nov 23 17:24:59 volumio-aph volumio[835]: info: sendMpdCommand status took 47 milliseconds Nov 23 17:24:59 volumio-aph volumio[835]: info: ControllerMpd::getState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand status Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::parseState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::parseState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::parseState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 23 17:24:59 volumio-aph volumio[835]: info: Nov 23 17:24:59 volumio-aph volumio[835]: ---------------------------- MPD announces state update: player Nov 23 17:24:59 volumio-aph volumio[835]: info: ControllerMpd::getState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand status Nov 23 17:24:59 volumio-aph volumio[835]: info: Nov 23 17:24:59 volumio-aph volumio[835]: ---------------------------- MPD announces state update: player Nov 23 17:24:59 volumio-aph volumio[835]: info: ControllerMpd::getState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand status Nov 23 17:24:59 volumio-aph volumio[835]: info: sendMpdCommand status took 49 milliseconds Nov 23 17:24:59 volumio-aph volumio[835]: info: ------------------------------ 57ms Nov 23 17:24:59 volumio-aph volumio[835]: info: sendMpdCommand status took 47 milliseconds Nov 23 17:24:59 volumio-aph volumio[835]: info: sendMpdCommand playlistinfo took 46 milliseconds Nov 23 17:24:59 volumio-aph volumio[835]: info: sendMpdCommand status took 41 milliseconds Nov 23 17:24:59 volumio-aph volumio[835]: info: sendMpdCommand status took 40 milliseconds Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::parseState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::parseState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::parseTrackInfo Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::parseTrackInfo Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::parseTrackInfo Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::parseState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::parseState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 23 17:24:59 volumio-aph volumio[835]: info: ControllerMpd::pushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::servicePushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:59 volumio-aph volumio[835]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"PATRICK HERNANDEZ - BORN TO BE ALIVE ","artist":"M-1 Plius","album":null,"uri":"http://radio.m-1.fm:80/m1plius/mp3","trackType":""} Nov 23 17:24:59 volumio-aph volumio[835]: verbose: CURRENT POSITION 0 Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::syncState stateService play Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::syncState currentStatus stop Nov 23 17:24:59 volumio-aph volumio[835]: info: ControllerMpd::pushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::servicePushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:59 volumio-aph volumio[835]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"PATRICK HERNANDEZ - BORN TO BE ALIVE ","artist":"M-1 Plius","album":null,"uri":"http://radio.m-1.fm:80/m1plius/mp3","trackType":""} Nov 23 17:24:59 volumio-aph volumio[835]: verbose: CURRENT POSITION 0 Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::syncState stateService play Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::syncState currentStatus play Nov 23 17:24:59 volumio-aph volumio[835]: info: Received an update from plugin. extracting info from payload Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:24:59 volumio-aph volumio[835]: info: ControllerMpd::pushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::servicePushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:59 volumio-aph volumio[835]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"PATRICK HERNANDEZ - BORN TO BE ALIVE ","artist":"M-1 Plius","album":null,"uri":"http://radio.m-1.fm:80/m1plius/mp3","trackType":""} Nov 23 17:24:59 volumio-aph volumio[835]: verbose: CURRENT POSITION 0 Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::syncState stateService play Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::syncState currentStatus play Nov 23 17:24:59 volumio-aph volumio[835]: info: Received an update from plugin. extracting info from payload Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:24:59 volumio-aph volumio[835]: info: ------------------------------ 167ms Nov 23 17:24:59 volumio-aph volumio[835]: info: ------------------------------ 187ms Nov 23 17:24:59 volumio-aph volumio[835]: info: ------------------------------ 179ms Nov 23 17:24:59 volumio-aph volumio[835]: info: Nov 23 17:24:59 volumio-aph volumio[835]: ---------------------------- MPD announces system playlist update Nov 23 17:24:59 volumio-aph volumio[835]: info: Ignoring MPD Status Update Nov 23 17:24:59 volumio-aph volumio[835]: info: Nov 23 17:24:59 volumio-aph volumio[835]: ---------------------------- MPD announces state update: player Nov 23 17:24:59 volumio-aph systemd[1]: systemd-hostnamed.service: Succeeded. Nov 23 17:24:59 volumio-aph volumio[835]: info: ControllerMpd::getState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand status Nov 23 17:24:59 volumio-aph volumio[835]: info: Nov 23 17:24:59 volumio-aph volumio[835]: ---------------------------- MPD announces system playlist update Nov 23 17:24:59 volumio-aph volumio[835]: info: Ignoring MPD Status Update Nov 23 17:24:59 volumio-aph volumio[835]: info: Nov 23 17:24:59 volumio-aph volumio[835]: ---------------------------- MPD announces state update: player Nov 23 17:24:59 volumio-aph volumio[835]: info: ControllerMpd::getState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand status Nov 23 17:24:59 volumio-aph volumio[835]: info: sendMpdCommand playlistinfo took 145 milliseconds Nov 23 17:24:59 volumio-aph volumio[835]: info: sendMpdCommand playlistinfo took 144 milliseconds Nov 23 17:24:59 volumio-aph volumio[835]: info: sendMpdCommand playlistinfo took 141 milliseconds Nov 23 17:24:59 volumio-aph volumio[835]: info: sendMpdCommand playlistinfo took 140 milliseconds Nov 23 17:24:59 volumio-aph volumio[835]: info: ------------------------------ 69ms Nov 23 17:24:59 volumio-aph volumio[835]: info: sendMpdCommand status took 44 milliseconds Nov 23 17:24:59 volumio-aph volumio[835]: info: ------------------------------ 42ms Nov 23 17:24:59 volumio-aph volumio[835]: info: sendMpdCommand status took 37 milliseconds Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::parseTrackInfo Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::parseTrackInfo Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::parseState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::parseState Nov 23 17:24:59 volumio-aph volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 23 17:24:59 volumio-aph volumio[835]: info: ControllerMpd::pushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::servicePushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:59 volumio-aph volumio[835]: verbose: STATE SERVICE {"status":"play","position":0,"seek":884,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"PATRICK HERNANDEZ - BORN TO BE ALIVE ","artist":"M-1 Plius","album":null,"uri":"http://radio.m-1.fm:80/m1plius/mp3","trackType":""} Nov 23 17:24:59 volumio-aph volumio[835]: verbose: CURRENT POSITION 0 Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::syncState stateService play Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::syncState currentStatus play Nov 23 17:24:59 volumio-aph volumio[835]: info: Received an update from plugin. extracting info from payload Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:24:59 volumio-aph volumio[835]: info: ControllerMpd::pushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::servicePushState Nov 23 17:24:59 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:24:59 volumio-aph volumio[835]: verbose: STATE SERVICE {"status":"play","position":0,"seek":884,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"PATRICK HERNANDEZ - BORN TO BE ALIVE ","artist":"M-1 Plius","album":null,"uri":"http://radio.m-1.fm:80/m1plius/mp3","trackType":""} Nov 23 17:24:59 volumio-aph volumio[835]: verbose: CURRENT POSITION 0 Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::syncState stateService play Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreStateMachine::syncState currentStatus play Nov 23 17:24:59 volumio-aph volumio[835]: info: Received an update from plugin. extracting info from payload Nov 23 17:24:59 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:25:00 volumio-aph volumio[835]: info: ControllerMpd::pushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::servicePushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:25:00 volumio-aph volumio[835]: verbose: STATE SERVICE {"status":"play","position":0,"seek":884,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"PATRICK HERNANDEZ - BORN TO BE ALIVE ","artist":"M-1 Plius","album":null,"uri":"http://radio.m-1.fm:80/m1plius/mp3","trackType":""} Nov 23 17:25:00 volumio-aph volumio[835]: verbose: CURRENT POSITION 0 Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::syncState stateService play Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::syncState currentStatus play Nov 23 17:25:00 volumio-aph volumio[835]: info: Received an update from plugin. extracting info from payload Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:25:00 volumio-aph volumio[835]: info: ControllerMpd::pushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::servicePushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:25:00 volumio-aph volumio[835]: verbose: STATE SERVICE {"status":"play","position":0,"seek":884,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"PATRICK HERNANDEZ - BORN TO BE ALIVE ","artist":"M-1 Plius","album":null,"uri":"http://radio.m-1.fm:80/m1plius/mp3","trackType":""} Nov 23 17:25:00 volumio-aph volumio[835]: verbose: CURRENT POSITION 0 Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::syncState stateService play Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::syncState currentStatus play Nov 23 17:25:00 volumio-aph volumio[835]: info: Received an update from plugin. extracting info from payload Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:25:00 volumio-aph volumio[835]: info: ------------------------------ 321ms Nov 23 17:25:00 volumio-aph volumio[835]: info: ------------------------------ 321ms Nov 23 17:25:00 volumio-aph volumio[835]: info: ------------------------------ 305ms Nov 23 17:25:00 volumio-aph volumio[835]: info: ------------------------------ 304ms Nov 23 17:25:00 volumio-aph volumio[835]: info: sendMpdCommand playlistinfo took 172 milliseconds Nov 23 17:25:00 volumio-aph volumio[835]: info: sendMpdCommand playlistinfo took 172 milliseconds Nov 23 17:25:00 volumio-aph volumio[835]: verbose: ControllerMpd::parseTrackInfo Nov 23 17:25:00 volumio-aph volumio[835]: verbose: ControllerMpd::parseTrackInfo Nov 23 17:25:00 volumio-aph volumio[835]: info: ControllerMpd::pushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::servicePushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:25:00 volumio-aph volumio[835]: verbose: STATE SERVICE {"status":"play","position":0,"seek":987,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"PATRICK HERNANDEZ - BORN TO BE ALIVE ","artist":"M-1 Plius","album":null,"uri":"http://radio.m-1.fm:80/m1plius/mp3","trackType":""} Nov 23 17:25:00 volumio-aph volumio[835]: verbose: CURRENT POSITION 0 Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::syncState stateService play Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::syncState currentStatus play Nov 23 17:25:00 volumio-aph volumio[835]: info: Received an update from plugin. extracting info from payload Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:25:00 volumio-aph volumio[835]: info: ControllerMpd::pushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::servicePushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CorePlayQueue::getTrack 0 Nov 23 17:25:00 volumio-aph volumio[835]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1079,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"PATRICK HERNANDEZ - BORN TO BE ALIVE ","artist":"M-1 Plius","album":null,"uri":"http://radio.m-1.fm:80/m1plius/mp3","trackType":""} Nov 23 17:25:00 volumio-aph volumio[835]: verbose: CURRENT POSITION 0 Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::syncState stateService play Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::syncState currentStatus play Nov 23 17:25:00 volumio-aph volumio[835]: info: Received an update from plugin. extracting info from payload Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreStateMachine::pushState Nov 23 17:25:00 volumio-aph volumio[835]: info: CoreCommandRouter::volumioPushState Nov 23 17:25:00 volumio-aph volumio[835]: info: ------------------------------ 304ms Nov 23 17:25:00 volumio-aph volumio[835]: info: ------------------------------ 277ms Nov 23 17:25:00 volumio-aph volumio[835]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Nov 23 17:25:00 volumio-aph volumio[835]: STREAMING PROXY: Starting server on port 3245 Nov 23 17:25:00 volumio-aph volumio[835]: Node JS runtime: 14 Nov 23 17:25:01 volumio-aph volumio[835]: info: MyVolumio token set successfully Nov 23 17:25:01 volumio-aph volumio[835]: info: MYVOLUMIO: Adding device Nov 23 17:25:01 volumio-aph volumio[835]: info: MYVOLUMIO: Evaluating Server Nov 23 17:25:01 volumio-aph volumio[835]: info: MyVolumio status changed Nov 23 17:25:01 volumio-aph volumio[835]: info: Streaming services startup Nov 23 17:25:01 volumio-aph volumio[835]: info: Starting Streaming Daemon Nov 23 17:25:01 volumio-aph volumio[835]: info: Removing browser output: myVolumio user plan is not superstar Nov 23 17:25:01 volumio-aph volumio[835]: info: Removing audio output: Nov 23 17:25:01 volumio-aph volumio[835]: info: Stoppping Tunnel 1 Nov 23 17:25:01 volumio-aph sudo[1268]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 23 17:25:01 volumio-aph sudo[1268]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:25:01 volumio-aph sudo[1271]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Nov 23 17:25:01 volumio-aph sudo[1271]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:25:01 volumio-aph sudo[1268]: pam_unix(sudo:session): session closed for user root Nov 23 17:25:01 volumio-aph volumio[835]: error: Cannot start Volumio Streaming Daemon Nov 23 17:25:01 volumio-aph volumio[835]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 23 17:25:01 volumio-aph volumio[835]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 23 17:25:01 volumio-aph sudo[1271]: pam_unix(sudo:session): session closed for user root Nov 23 17:25:01 volumio-aph volumio[835]: info: Remote SSH Stopped Nov 23 17:25:01 volumio-aph volumio[835]: info: Setting Geolocation for MyVolumio to eu4 Nov 23 17:25:01 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 17:25:02 volumio-aph volumio[835]: info: Successfully Added MyVolumio device Nov 23 17:25:02 volumio-aph volumio[835]: info: Updating MyVolumio device info Nov 23 17:25:02 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 23 17:25:03 volumio-aph volumio[835]: info: Successfully Updated MyVolumio device Nov 23 17:25:06 volumio-aph volumio[1190]: .......................................................................................................................++++ Nov 23 17:25:06 volumio-aph volumio[1190]: e is 65537 (0x010001) Nov 23 17:25:06 volumio-aph volumio[1190]: writing RSA key Nov 23 17:25:08 volumio-aph systemd[1]: systemd-timedated.service: Succeeded. Nov 23 17:25:12 volumio-aph volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 23 17:25:12 volumio-aph volumio[835]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Nov 23 17:25:12 volumio-aph volumio[835]: info: CoreCommandRouter::volumioGetState Nov 23 17:25:14 volumio-aph volumio[835]: info: ___________ PLUGINS: Run Shutdown Tasks ___________ Nov 23 17:25:14 volumio-aph volumio[835]: info: PLUGIN onShutdown : networkfs Nov 23 17:25:14 volumio-aph sudo[1345]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount -f /mnt/NAS/NAMU_SERVER Nov 23 17:25:14 volumio-aph sudo[1345]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 23 17:25:14 volumio-aph sudo[1345]: pam_unix(sudo:session): session closed for user root Nov 23 17:25:14 volumio-aph systemd[1]: mnt-NAS-NAMU_SERVER.mount: Succeeded. Nov 23 17:25:14 volumio-aph volumio[835]: info: PLUGIN onShutdown : audiophonicsonoff Nov 23 17:25:14 volumio-aph volumio[835]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 23 17:25:14 volumio-aph volumio[835]: TypeError: Cannot read property 'writeSync' of undefined Nov 23 17:25:14 volumio-aph volumio[835]: at ControllerAudiophonicsOnOff.onVolumioShutdown (/data/plugins/system_controller/audiophonicsonoff/index.js:43:25) Nov 23 17:25:14 volumio-aph volumio[835]: at PluginManager.onVolumioShutdownPlugin (/volumio/app/pluginmanager.js:638:30) Nov 23 17:25:14 volumio-aph volumio[835]: at HashMap. (/volumio/app/pluginmanager.js:621:31) Nov 23 17:25:14 volumio-aph volumio[835]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Nov 23 17:25:14 volumio-aph volumio[835]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Nov 23 17:25:14 volumio-aph volumio[835]: at PluginManager.onVolumioShutdown (/volumio/app/pluginmanager.js:619:20) Nov 23 17:25:14 volumio-aph volumio[835]: at CoreCommandRouter.shutdown (/volumio/app/index.js:1333:24) Nov 23 17:25:14 volumio-aph volumio[835]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:859:33) Nov 23 17:25:14 volumio-aph volumio[835]: at Socket.emit (events.js:315:20) Nov 23 17:25:14 volumio-aph volumio[835]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Nov 23 17:25:14 volumio-aph volumio[835]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Nov 23 17:25:14 volumio-aph volumio[835]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 23 17:25:15 volumio-aph sudo[1357]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-23 17:24 Nov 23 17:25:15 volumio-aph sudo[1357]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"