Apr 23 21:09:50 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken Apr 23 21:09:50 volumio volumio[2782]: info: MyVolumio login type: Token Apr 23 21:09:50 volumio volumio[2782]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Apr 23 21:09:50 volumio volumio[2782]: info: MyVolumio token set successfully Apr 23 21:09:50 volumio volumio[2782]: info: MYVOLUMIO: Adding device Apr 23 21:09:50 volumio volumio[2782]: info: MYVOLUMIO: Evaluating Server Apr 23 21:09:51 volumio volumio[2782]: info: MyVolumio Plan changed: premium Apr 23 21:09:51 volumio volumio[2782]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Apr 23 21:09:51 volumio volumio[2782]: info: Removing browser output: myVolumio user plan is not superstar Apr 23 21:09:51 volumio volumio[2782]: info: Removing audio output: Apr 23 21:09:51 volumio volumio[2782]: info: MYVOLUMIO: Adding device Apr 23 21:09:51 volumio volumio[2782]: info: MYVOLUMIO: Evaluating Server Apr 23 21:09:51 volumio volumio[2782]: info: Remote config written successfully Apr 23 21:09:51 volumio volumio[2782]: info: Starting Tunnel 1 Apr 23 21:09:51 volumio volumio[2782]: info: Starting Tunnel Connection Checker Apr 23 21:09:51 volumio volumio[2782]: info: MYVolumio Device enabled Apr 23 21:09:51 volumio volumio[2782]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Apr 23 21:09:51 volumio volumio[2782]: info: MyVolumio status changed Apr 23 21:09:51 volumio volumio[2782]: info: Streaming services startup Apr 23 21:09:51 volumio volumio[2782]: info: Starting Streaming Daemon Apr 23 21:09:51 volumio sudo[3369]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Apr 23 21:09:51 volumio sudo[3369]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:51 volumio volumio[2782]: error: [MyVolumio PluginManager] Could not read cache file: ENOENT: no such file or directory, open '/data/myvolumio/cache.data' Apr 23 21:09:51 volumio sudo[3369]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:51 volumio volumio[2782]: error: Cannot start Volumio Streaming Daemon Apr 23 21:09:51 volumio volumio[2782]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 23 21:09:51 volumio volumio[2782]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 23 21:09:51 volumio volumio[2782]: info: Setting Geolocation for MyVolumio to eu9 Apr 23 21:09:51 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:51 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:51 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:51 volumio volumio[2782]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Apr 23 21:09:52 volumio volumio[2782]: ------------------------------------ BT MESSAGE: [FUNC] onVolumioStart Apr 23 21:09:52 volumio volumio[2782]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Apr 23 21:09:53 volumio sudo[3374]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Apr 23 21:09:53 volumio sudo[3374]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:53 volumio sudo[3374]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:53 volumio volumio[2782]: info: MRS: MultiRoom plugin initialized Apr 23 21:09:53 volumio volumio[2782]: info: MRS: STOPPING SNAPCLIENT Apr 23 21:09:53 volumio volumio[2782]: info: MRS: Snap server stop Apr 23 21:09:53 volumio volumio[2782]: info: MRS: STOPPING volumioStreaming Apr 23 21:09:53 volumio sudo[3391]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Apr 23 21:09:53 volumio sudo[3391]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Apr 23 21:09:53 volumio sudo[3393]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Apr 23 21:09:53 volumio sudo[3393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:53 volumio sudo[3395]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Apr 23 21:09:53 volumio sudo[3395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:53 volumio sudo[3398]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Apr 23 21:09:53 volumio sudo[3398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Apr 23 21:09:53 volumio sudo[3398]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Apr 23 21:09:53 volumio sudo[3393]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:53 volumio sudo[3395]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:53 volumio sudo[3391]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Apr 23 21:09:53 volumio volumio[2782]: info: Preparing to generate the ALSA configuration file Apr 23 21:09:53 volumio volumio[2782]: info: Updating MyVolumio device info Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Apr 23 21:09:53 volumio volumio[2782]: info: Setting Geolocation for MyVolumio to eu5 Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: Successfully Added MyVolumio device Apr 23 21:09:53 volumio volumio[2782]: info: MRS: Removed streaming files Apr 23 21:09:53 volumio volumio[2782]: info: MRS: volumioStreaming STOPPED Apr 23 21:09:53 volumio volumio[2782]: info: MRS: SNAPSERVER STOPPED Apr 23 21:09:53 volumio volumio[2782]: info: MRS: SNAPCLIENT STOPPED Apr 23 21:09:53 volumio volumio[2782]: info: Asound.conf file unchanged, so no further update is needed Apr 23 21:09:53 volumio volumio[2782]: info: Output device has changed, restarting MPD Apr 23 21:09:53 volumio volumio[2782]: info: Output device has changed, restarting Shairport Sync Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:53 volumio sudo[3405]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 23 21:09:53 volumio sudo[3405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:53 volumio sudo[3407]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 23 21:09:53 volumio sudo[3407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:53 volumio sudo[3405]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:53 volumio volumio[2782]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 23 21:09:53 volumio volumio[2782]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:53 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Apr 23 21:09:53 volumio volumio[2782]: ------------------------------------ BT MESSAGE: [FUNC] onStart Apr 23 21:09:53 volumio volumio[2782]: ------------------------------------ BT MESSAGE: Starting Volumio Bluetooth Service Apr 23 21:09:53 volumio volumio[2782]: ------------------------------------ BT MESSAGE: Boot config /etc/bluetooth/volumio.conf: cache mode = tmp Apr 23 21:09:53 volumio volumio[2782]: ------------------------------------ BT MESSAGE: [metaCache] Created directory: /tmp/bluetooth-cache/ Apr 23 21:09:53 volumio volumio[2782]: ------------------------------------ BT MESSAGE: [metaCache] Directory exists and is ready. Apr 23 21:09:53 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 23 21:09:53 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 23 21:09:53 volumio systemd[1]: mpd.service: Consumed 1.602s CPU time. Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus Apr 23 21:09:53 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 23 21:09:53 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 23 21:09:53 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 23 21:09:53 volumio volumio[2782]: info: MRS: Pushing multiroomSync output for this device Apr 23 21:09:53 volumio volumio[2782]: info: MRS: Pushing multiroomSync output Apr 23 21:09:53 volumio volumio[2782]: info: Adding audio output: Apr 23 21:09:53 volumio volumio[2782]: info: Adding audio output: Apr 23 21:09:53 volumio volumio[2782]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Apr 23 21:09:53 volumio volumio[2782]: info: Adding METAVOLUMIO REST API Endpoints Apr 23 21:09:53 volumio volumio[2782]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Apr 23 21:09:53 volumio volumio[2782]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Apr 23 21:09:53 volumio volumio[2782]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Apr 23 21:09:53 volumio volumio[2782]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Apr 23 21:09:53 volumio volumio[2782]: info: Preparing CD Folders Apr 23 21:09:53 volumio volumio[2782]: info: Adding CD REST API Endpoints Apr 23 21:09:53 volumio volumio[2782]: info: Adding cdPostRip REST Endpoint for plugin: music_service/cd_controller Apr 23 21:09:53 volumio volumio[2782]: info: Starting UDEV Watcher for CD Apr 23 21:09:53 volumio volumio[2782]: info: Detecting CD presence with UDEV Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: networkfs , getUdevDevices Apr 23 21:09:53 volumio bluetoothd[687]: Path / reserved for Adv Monitor app :1.38 Apr 23 21:09:53 volumio bluetoothd[687]: Adv Monitor app :1.38 disconnected from D-Bus Apr 23 21:09:53 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 23 21:09:53 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Apr 23 21:09:53 volumio volumio[2782]: info: Adding inputs REST Endpoints Apr 23 21:09:53 volumio volumio[2782]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Apr 23 21:09:53 volumio volumio[2782]: info: Scanning Audio Inputs Apr 23 21:09:53 volumio volumio[2782]: info: Checking against Known Cards name Apr 23 21:09:53 volumio volumio[2782]: info: Adding Server instance for streaming Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Apr 23 21:09:53 volumio volumio[2782]: error: Hi Res Audio Failed Login: Missing Login Data Apr 23 21:09:53 volumio volumio[2782]: info: Adding HIGHRESAUDIO REST API Endpoints Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Apr 23 21:09:53 volumio volumio[2782]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Apr 23 21:09:53 volumio volumio[2782]: info: Stopping AccessToken refresher cron Apr 23 21:09:53 volumio sudo[3427]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 23 21:09:53 volumio sudo[3427]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:53 volumio volumio[2782]: info: AccessToken refresher cron started Apr 23 21:09:53 volumio volumio[2782]: info: Stopping AccessToken refresher cron for QOBUZ Apr 23 21:09:53 volumio sudo[3427]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:53 volumio volumio[2782]: info: AccessToken refresher cron started for QOBUZ Apr 23 21:09:53 volumio volumio[2782]: info: Adding TIDAL REST API Endpoints Apr 23 21:09:53 volumio volumio[2782]: info: Adding QOBUZ REST API Endpoints Apr 23 21:09:53 volumio sudo[3422]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 23 21:09:53 volumio sudo[3422]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 23 21:09:53 volumio sudo[3422]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:53 volumio volumio[2782]: info: MRS: Adding multiroomSync output Apr 23 21:09:53 volumio volumio[2782]: info: Adding audio output: Apr 23 21:09:53 volumio volumio[2782]: info: MRS: Pushing multiroomSync output Apr 23 21:09:53 volumio volumio[2782]: ------------------------------------ BT MESSAGE: Bluetooth adapter powered on Apr 23 21:09:53 volumio volumio[2782]: info: MPD Permissions set Apr 23 21:09:53 volumio volumio[2782]: info: Successfully Updated MyVolumio device Apr 23 21:09:53 volumio sudo[3433]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Apr 23 21:09:53 volumio sudo[3433]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:53 volumio volumio[2782]: info: Starting Shairport Sync Apr 23 21:09:53 volumio systemd[1]: Started volumiobt.service - Volumio Bluetooth Module. Apr 23 21:09:53 volumio sudo[3433]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:54 volumio volumio[2782]: info: Preparing to generate the ALSA configuration file Apr 23 21:09:54 volumio volumiobt[3443]: INFO [BTSTART] Ensuring Bluetooth directory exists... Apr 23 21:09:54 volumio sudo[3442]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 23 21:09:54 volumio sudo[3442]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:54 volumio volumio[2782]: ------------------------------------ BT MESSAGE: volumiobt.service started successfully Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::volumioStop Apr 23 21:09:54 volumio volumio[2782]: info: CoreStateMachine::stop Apr 23 21:09:54 volumio volumio[2782]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 23 21:09:54 volumio volumio[2782]: ------------------------------------ BT MESSAGE: [FUNC] dbusStart Apr 23 21:09:54 volumio volumio[2782]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 23 21:09:54 volumio sudo[3444]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/mkdir -p /var/lib/bluetooth Apr 23 21:09:54 volumio sudo[3444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:54 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 23 21:09:54 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 23 21:09:54 volumio sudo[3444]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:54 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 23 21:09:54 volumio systemd[1]: shairport-sync.service: Consumed 1.793s CPU time. Apr 23 21:09:54 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 23 21:09:54 volumio sudo[3447]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth Apr 23 21:09:54 volumio sudo[3442]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:54 volumio sudo[3447]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:54 volumio sudo[3447]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:54 volumio volumiobt[3450]: INFO [BTSTART] Powering on Bluetooth if needed... Apr 23 21:09:54 volumio volumio[2782]: info: Asound.conf file unchanged, so no further update is needed Apr 23 21:09:54 volumio volumio[2782]: info: Output device has changed, restarting MPD Apr 23 21:09:54 volumio sudo[3454]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 23 21:09:54 volumio sudo[3454]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:54 volumio volumio[2782]: info: Output device has changed, restarting Shairport Sync Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:54 volumio sudo[3454]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:54 volumio bluetoothd[687]: Adv Monitor app :1.39 disconnected from D-Bus Apr 23 21:09:54 volumio volumiobt[3472]: INFO [BTSTART] Making Bluetooth discoverable and pairable... Apr 23 21:09:54 volumio sudo[3468]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 23 21:09:54 volumio sudo[3468]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:54 volumio volumio[2782]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 23 21:09:54 volumio volumio[2782]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumiobt[3473]: [75B blob data] Apr 23 21:09:54 volumio volumiobt[3473]: [bluetooth]# pairable on Apr 23 21:09:54 volumio volumiobt[3473]: [bluetooth]# Apr 23 21:09:54 volumio volumiobt[3481]: INFO [BTSTART] Registering Bluetooth agent... Apr 23 21:09:54 volumio bluetoothd[687]: Adv Monitor app :1.42 disconnected from D-Bus Apr 23 21:09:54 volumio volumio[2782]: info: Preparing to generate the ALSA configuration file Apr 23 21:09:54 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 23 21:09:54 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 23 21:09:54 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 23 21:09:54 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 23 21:09:54 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 23 21:09:54 volumio volumio[2782]: info: Shairport-Sync Started Apr 23 21:09:54 volumio volumio[2782]: info: MPD Permissions set Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio bluetoothd[687]: Adv Monitor app :1.43 disconnected from D-Bus Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: Asound.conf file unchanged, so no further update is needed Apr 23 21:09:54 volumio volumio[2782]: info: Output device has changed, restarting MPD Apr 23 21:09:54 volumio volumiobt[3486]: No agent is registered Apr 23 21:09:54 volumio volumiobt[3493]: INFO [BTSTART] Agent registered successfully. Apr 23 21:09:54 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 23 21:09:54 volumio volumio[2782]: info: Output device has changed, restarting Shairport Sync Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:54 volumio bluetoothd[687]: Adv Monitor app :1.44 disconnected from D-Bus Apr 23 21:09:54 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 23 21:09:54 volumio volumiobt[3499]: INFO [BTSTART] Starting A2DP agent (a2dp-agent)... Apr 23 21:09:54 volumio sudo[3492]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 23 21:09:54 volumio sudo[3492]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:54 volumio sudo[3492]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:54 volumio sudo[3495]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 23 21:09:54 volumio sudo[3495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:54 volumio volumio[2782]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 23 21:09:54 volumio volumio[2782]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: Updating MyVolumio device info Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: MPD Permissions set Apr 23 21:09:54 volumio volumio[2782]: info: Successfully Added MyVolumio device Apr 23 21:09:54 volumio volumio[2782]: info: Starting Shairport Sync Apr 23 21:09:54 volumio systemd[1]: mpd.service: Deactivated successfully. Apr 23 21:09:54 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Apr 23 21:09:54 volumio systemd[1]: mpd.socket: Deactivated successfully. Apr 23 21:09:54 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Apr 23 21:09:54 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio sudo[3509]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 23 21:09:54 volumio sudo[3509]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:09:54 volumio volumio[2782]: info: Starting Shairport Sync Apr 23 21:09:54 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Apr 23 21:09:54 volumio sudo[3518]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 23 21:09:54 volumio sudo[3518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:54 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Apr 23 21:09:54 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 23 21:09:54 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 23 21:09:54 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 23 21:09:54 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 23 21:09:54 volumio volumio[2782]: info: Shairport-Sync Started Apr 23 21:09:54 volumio sudo[3518]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:54 volumio sudo[3509]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:54 volumio volumio[2782]: info: Shairport-Sync Started Apr 23 21:09:54 volumio volumio[2782]: info: Successfully Updated MyVolumio device Apr 23 21:09:54 volumio sudo[3519]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Apr 23 21:09:54 volumio sudo[3519]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Apr 23 21:09:54 volumio sudo[3519]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:55 volumio volumiobt[3500]: INFO:a2dp-agent:Connecting to system bus. Apr 23 21:09:55 volumio volumiobt[3500]: INFO:a2dp-agent:Found Bluetooth adapter at: /org/bluez/hci0 Apr 23 21:09:55 volumio volumiobt[3500]: INFO:a2dp-agent:Enabling infinite discovery on adapter. Apr 23 21:09:55 volumio volumiobt[3500]: INFO:a2dp-agent:Registering agent. Apr 23 21:09:55 volumio volumiobt[3500]: INFO:a2dp-agent:Searching for MediaPlayer1 interface... Apr 23 21:09:55 volumio volumiobt[3500]: WARNING:a2dp-agent:No active MediaPlayer1 found. Metadata updates won't work. Apr 23 21:09:55 volumio mpd[3536]: Apr 23 21:09 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 23 21:09:55 volumio systemd[1]: Started mpd.service - Music Player Daemon. Apr 23 21:09:55 volumio sudo[3407]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:55 volumio sudo[3495]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:55 volumio sudo[3468]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:55 volumio volumio[2782]: error: MPD error: The expression evaluated to a falsy value: Apr 23 21:09:55 volumio volumio[2782]: assert.ok(self.idling) Apr 23 21:09:55 volumio volumio[2782]: error: The expression evaluated to a falsy value: Apr 23 21:09:55 volumio volumio[2782]: assert.ok(self.idling) Apr 23 21:09:55 volumio volumio[2782]: error: MPD error: The expression evaluated to a falsy value: Apr 23 21:09:55 volumio volumio[2782]: assert.ok(self.idling) Apr 23 21:09:55 volumio volumio[2782]: error: The expression evaluated to a falsy value: Apr 23 21:09:55 volumio volumio[2782]: assert.ok(self.idling) Apr 23 21:09:55 volumio volumio[2782]: error: updateQueue error: null Apr 23 21:09:56 volumio sudo[3546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Apr 23 21:09:56 volumio sudo[3546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:56 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 23 21:09:56 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Apr 23 21:09:56 volumio systemd[1]: Started sshtunnel.service - MyVolumio SSH Tunnel. Apr 23 21:09:56 volumio sudo[3546]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:56 volumio volumio[2782]: info: Remote SSH Started Apr 23 21:09:56 volumio autossh[3563]: port set to 0, monitoring disabled Apr 23 21:09:56 volumio autossh[3563]: starting ssh (count 1) Apr 23 21:09:56 volumio autossh[3563]: ssh child pid is 3566 Apr 23 21:09:56 volumio volumio[2782]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Apr 23 21:09:56 volumio volumio[2782]: info: CoreCommandRouter::volumioGetState Apr 23 21:09:56 volumio volumio[2782]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.h0PZQsB39AURSlylidLe37OavVF3.88dd99399252828aa992fa9b2610eee3.state.status' Apr 23 21:09:56 volumio volumiossh-tunnel[3566]: Warning: Permanently added '[eu5.myvolumio.org]:2222' (RSA) to the list of known hosts. Apr 23 21:09:56 volumio volumio[2782]: info: TidalConnect service stoped! Apr 23 21:09:56 volumio volumio[2782]: info: Adding tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 23 21:09:56 volumio volumio[2782]: info: Adding tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 23 21:09:56 volumio sudo[3576]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 23 21:09:56 volumio sudo[3576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:57 volumio systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Apr 23 21:09:57 volumio sudo[3576]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:57 volumio volumio[2782]: info: Executing endpoint tc_getconfig Apr 23 21:09:57 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Apr 23 21:09:57 volumio vtcs[3579]: STARTING TidalConnect services, version: 1.5.0.45 Apr 23 21:09:57 volumio vtcs[3579]: STARTED TidalConnect services. Apr 23 21:09:57 volumio volumio[2782]: info: Executing endpoint tc_connect Apr 23 21:09:57 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Apr 23 21:09:57 volumio volumio[2782]: info: Connecting to TidalConnect Apr 23 21:09:57 volumio volumio[2782]: info: CoreCommandRouter::servicePushState Apr 23 21:09:57 volumio volumio[2782]: info: CoreStateMachine::pushState Apr 23 21:09:57 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 23 21:09:57 volumio volumio[2782]: info: CoreCommandRouter::volumioPushState Apr 23 21:09:57 volumio volumio[2782]: info: MRS: Pushing multiroomSync output update for this device Apr 23 21:09:57 volumio volumio[2782]: info: MRS: Pushing multiroomSync output Apr 23 21:09:57 volumio volumio[2782]: info: CorePlayQueue::getTrack 0 Apr 23 21:09:57 volumio volumio[2782]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Apr 23 21:09:57 volumio volumio[2782]: verbose: CURRENT POSITION 0 Apr 23 21:09:57 volumio volumio[2782]: info: CoreStateMachine::syncState stateService stop Apr 23 21:09:57 volumio volumio[2782]: info: CoreStateMachine::syncState currentStatus stop Apr 23 21:09:57 volumio volumio[2782]: info: CoreStateMachine::pushState Apr 23 21:09:57 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 23 21:09:57 volumio volumio[2782]: info: CoreCommandRouter::volumioPushState Apr 23 21:09:57 volumio volumio[2782]: info: MRS: Pushing multiroomSync output update for this device Apr 23 21:09:57 volumio volumio[2782]: info: MRS: Pushing multiroomSync output Apr 23 21:09:57 volumio volumio[2782]: info: No code Apr 23 21:09:57 volumio volumio[2782]: info: CoreStateMachine::pushState Apr 23 21:09:57 volumio volumio[2782]: info: CoreCommandRouter::volumioPushState Apr 23 21:09:57 volumio volumio[2782]: info: MRS: Pushing multiroomSync output update for this device Apr 23 21:09:57 volumio volumio[2782]: info: MRS: Pushing multiroomSync output Apr 23 21:09:57 volumio volumio[2782]: info: CoreCommandRouter::servicePushState Apr 23 21:09:57 volumio volumio[2782]: info: CoreStateMachine::pushState Apr 23 21:09:57 volumio volumio[2782]: info: CoreCommandRouter::volumioPushState Apr 23 21:09:57 volumio volumio[2782]: info: MRS: Pushing multiroomSync output update for this device Apr 23 21:09:57 volumio volumio[2782]: info: MRS: Pushing multiroomSync output Apr 23 21:09:57 volumio volumio[2782]: info: CorePlayQueue::getTrack 0 Apr 23 21:09:57 volumio volumio[2782]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Apr 23 21:09:57 volumio volumio[2782]: verbose: CURRENT POSITION 0 Apr 23 21:09:57 volumio volumio[2782]: info: CoreStateMachine::syncState stateService stop Apr 23 21:09:57 volumio volumio[2782]: info: CoreStateMachine::syncState currentStatus stop Apr 23 21:09:57 volumio volumio[2782]: info: CoreStateMachine::pushState Apr 23 21:09:57 volumio volumio[2782]: info: CoreCommandRouter::volumioPushState Apr 23 21:09:57 volumio volumio[2782]: info: MRS: Pushing multiroomSync output update for this device Apr 23 21:09:57 volumio volumio[2782]: info: MRS: Pushing multiroomSync output Apr 23 21:09:57 volumio volumio[2782]: info: No code Apr 23 21:09:57 volumio volumio[2782]: info: CoreStateMachine::pushState Apr 23 21:09:57 volumio volumio[2782]: info: CoreCommandRouter::volumioPushState Apr 23 21:09:57 volumio volumio[2782]: info: MRS: Pushing multiroomSync output update for this device Apr 23 21:09:57 volumio volumio[2782]: info: MRS: Pushing multiroomSync output Apr 23 21:09:57 volumio volumio[2782]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.h0PZQsB39AURSlylidLe37OavVF3.88dd99399252828aa992fa9b2610eee3.state.status' Apr 23 21:09:57 volumio volumio[2782]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.h0PZQsB39AURSlylidLe37OavVF3.88dd99399252828aa992fa9b2610eee3.state.status' Apr 23 21:09:57 volumio volumio[2782]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.h0PZQsB39AURSlylidLe37OavVF3.88dd99399252828aa992fa9b2610eee3.state.status' Apr 23 21:09:57 volumio volumio[2782]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.h0PZQsB39AURSlylidLe37OavVF3.88dd99399252828aa992fa9b2610eee3.state.status' Apr 23 21:09:58 volumio volumio[2782]: info: MRS: Getting audio outputs on start Apr 23 21:09:58 volumio volumio[2782]: info: MRS: Requesting all other devices output Apr 23 21:09:59 volumio sudo[3596]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 23 21:09:59 volumio sudo[3596]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:59 volumio sudo[3596]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:59 volumio sudo[3598]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 23 21:09:59 volumio sudo[3598]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:09:59 volumio sudo[3598]: pam_unix(sudo:session): session closed for user root Apr 23 21:09:59 volumio volumio[2782]: verbose: New Socket.io Connection to 192.168.178.154 from 192.168.178.18 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/134.0.0.0 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Apr 23 21:09:59 volumio volumio[2782]: info: Received Get System Info Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 23 21:09:59 volumio volumio[2782]: info: Discovery: Getting this device information Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::volumioGetState Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::volumioGetState Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::volumioGetVisibleSources Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::volumioGetState Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 23 21:09:59 volumio volumio[2782]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Apr 23 21:09:59 volumio volumio[2782]: info: Received Get System Info Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 23 21:09:59 volumio volumio[2782]: info: Discovery: Getting this device information Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::volumioGetState Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::volumioGetState Apr 23 21:09:59 volumio volumio[2782]: info: Listing playlists Apr 23 21:09:59 volumio volumio[2782]: info: Received Get System Info Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 23 21:09:59 volumio volumio[2782]: info: Discovery: Getting this device information Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::volumioGetState Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 23 21:09:59 volumio volumio[2782]: info: CoreCommandRouter::volumioGetState Apr 23 21:10:00 volumio volumio[2782]: info: TidalConnect service started! Apr 23 21:10:00 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 23 21:10:04 volumio volumio[2782]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 23 21:10:04 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 23 21:10:04 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 23 21:10:04 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Apr 23 21:10:04 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Apr 23 21:10:05 volumio volumio[2782]: info: Received Get System Version Apr 23 21:10:05 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 23 21:10:09 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 23 21:10:20 volumio volumio[2782]: info: CALLMETHOD: system_controller system saveGeneralSettings [object Object] Apr 23 21:10:20 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , saveGeneralSettings Apr 23 21:10:20 volumio volumio[2782]: info: System name has changed, restarting Shairport Sync Apr 23 21:10:20 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 23 21:10:20 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:10:20 volumio volumio[2782]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 23 21:10:20 volumio volumio[2782]: info: Updating MyVolumio device info Apr 23 21:10:20 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:10:20 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:10:20 volumio volumio[2782]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 23 21:10:20 volumio vtcs[3579]: [2025-04-23 21:10:20.499] [tisoc] [error] [SpkconServer.cpp:375] recv error. socket disconnected Apr 23 21:10:20 volumio vtcs[3579]: [2025-04-23 21:10:20.500] [tisoc] [warning] [SessionManagerImpl.cpp:240] Illegal State: IDLE Apr 23 21:10:20 volumio volumio[2782]: info: Discovery: Restarting Advertising due to device name change Apr 23 21:10:20 volumio sudo[3655]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 23 21:10:20 volumio sudo[3655]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:10:20 volumio sudo[3657]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/killall upmpdcli Apr 23 21:10:20 volumio sudo[3657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:10:20 volumio sudo[3660]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Apr 23 21:10:20 volumio sudo[3660]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:10:20 volumio sudo[3657]: pam_unix(sudo:session): session closed for user root Apr 23 21:10:20 volumio systemd[1]: Stopping vtcs.service - Volumio Tidal Connect Service... Apr 23 21:10:20 volumio systemd[1]: vtcs.service: Killing process 3586 (vtcs) with signal SIGKILL. Apr 23 21:10:20 volumio volumio[2782]: info: Starting Shairport Sync Apr 23 21:10:20 volumio sudo[3664]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hosts Apr 23 21:10:20 volumio sudo[3664]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:10:20 volumio systemd[1]: vtcs.service: Deactivated successfully. Apr 23 21:10:20 volumio systemd[1]: Stopped vtcs.service - Volumio Tidal Connect Service. Apr 23 21:10:20 volumio sudo[3655]: pam_unix(sudo:session): session closed for user root Apr 23 21:10:20 volumio sudo[3666]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 23 21:10:20 volumio sudo[3666]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:10:20 volumio sudo[3660]: pam_unix(sudo:session): session closed for user root Apr 23 21:10:20 volumio sudo[3664]: pam_unix(sudo:session): session closed for user root Apr 23 21:10:20 volumio volumio[2782]: info: Permissions for /etc/hosts set Apr 23 21:10:20 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Apr 23 21:10:20 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Apr 23 21:10:20 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 23 21:10:20 volumio systemd[1]: shairport-sync.service: Consumed 1.599s CPU time. Apr 23 21:10:20 volumio volumio[2782]: info: Hostname now is sibermusic Apr 23 21:10:20 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Apr 23 21:10:20 volumio sudo[3666]: pam_unix(sudo:session): session closed for user root Apr 23 21:10:20 volumio volumio[2782]: info: Shairport-Sync Started Apr 23 21:10:20 volumio sudo[3674]: volumio : unable to resolve host volumio: System error Apr 23 21:10:20 volumio sudo[3674]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/hostname sibermusic Apr 23 21:10:20 volumio sudo[3674]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:10:20 sibermusic sudo[3674]: pam_unix(sudo:session): session closed for user root Apr 23 21:10:20 sibermusic sudo[3677]: volumio : unable to resolve host volumio: System error Apr 23 21:10:20 sibermusic volumio[2782]: info: New hostname set Apr 23 21:10:20 sibermusic sudo[3677]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /etc/avahi/services/ Apr 23 21:10:20 sibermusic sudo[3677]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:10:20 sibermusic sudo[3677]: pam_unix(sudo:session): session closed for user root Apr 23 21:10:20 sibermusic volumio[2782]: info: Permissions for /etc/avahi/services/volumio.service Apr 23 21:10:20 sibermusic avahi-daemon[684]: Files changed, reloading. Apr 23 21:10:20 sibermusic volumio[2782]: info: Avahi name changed to sibermusic Apr 23 21:10:20 sibermusic avahi-daemon[684]: Loading service file /services/volumio.service. Apr 23 21:10:20 sibermusic volumio[2782]: info: Successfully Updated MyVolumio device Apr 23 21:10:21 sibermusic volumio[2782]: info: Discovery: A device disappeared from network Apr 23 21:10:21 sibermusic volumio[2782]: info: Discovery: Device volumio disappeared from network Apr 23 21:10:21 sibermusic volumio[2782]: info: Discovery: A device disappeared from network Apr 23 21:10:21 sibermusic avahi-daemon[684]: Service "sibermusic" (/services/volumio.service) successfully established. Apr 23 21:10:23 sibermusic volumio[2782]: info: TidalConnect service stoped! Apr 23 21:10:23 sibermusic volumio[2782]: info: TidalConnect service stoped! Apr 23 21:10:23 sibermusic volumio[2782]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Apr 23 21:10:23 sibermusic volumio[2782]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Apr 23 21:10:23 sibermusic sudo[3703]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Apr 23 21:10:23 sibermusic sudo[3703]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Apr 23 21:10:23 sibermusic systemd[1]: Started vtcs.service - Volumio Tidal Connect Service. Apr 23 21:10:23 sibermusic sudo[3703]: pam_unix(sudo:session): session closed for user root Apr 23 21:10:24 sibermusic volumio[2782]: info: Executing endpoint tc_getconfig Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Apr 23 21:10:24 sibermusic vtcs[3706]: STARTING TidalConnect services, version: 1.5.0.45 Apr 23 21:10:24 sibermusic vtcs[3706]: STARTED TidalConnect services. Apr 23 21:10:24 sibermusic volumio[2782]: info: Executing endpoint tc_connect Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Apr 23 21:10:24 sibermusic volumio[2782]: info: Connecting to TidalConnect Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreCommandRouter::servicePushState Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreStateMachine::pushState Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreCommandRouter::volumioPushState Apr 23 21:10:24 sibermusic volumio[2782]: info: MRS: Pushing multiroomSync output update for this device Apr 23 21:10:24 sibermusic volumio[2782]: info: MRS: Pushing multiroomSync output Apr 23 21:10:24 sibermusic volumio[2782]: info: CorePlayQueue::getTrack 0 Apr 23 21:10:24 sibermusic volumio[2782]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Apr 23 21:10:24 sibermusic volumio[2782]: verbose: CURRENT POSITION 0 Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreStateMachine::syncState stateService stop Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreStateMachine::syncState currentStatus stop Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreStateMachine::pushState Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreCommandRouter::volumioPushState Apr 23 21:10:24 sibermusic volumio[2782]: info: MRS: Pushing multiroomSync output update for this device Apr 23 21:10:24 sibermusic volumio[2782]: info: MRS: Pushing multiroomSync output Apr 23 21:10:24 sibermusic volumio[2782]: info: No code Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreStateMachine::pushState Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreCommandRouter::volumioPushState Apr 23 21:10:24 sibermusic volumio[2782]: info: MRS: Pushing multiroomSync output update for this device Apr 23 21:10:24 sibermusic volumio[2782]: info: MRS: Pushing multiroomSync output Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreCommandRouter::servicePushState Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreStateMachine::pushState Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreCommandRouter::volumioPushState Apr 23 21:10:24 sibermusic volumio[2782]: info: MRS: Pushing multiroomSync output update for this device Apr 23 21:10:24 sibermusic volumio[2782]: info: MRS: Pushing multiroomSync output Apr 23 21:10:24 sibermusic volumio[2782]: info: CorePlayQueue::getTrack 0 Apr 23 21:10:24 sibermusic volumio[2782]: verbose: STATE SERVICE {"status":"stop","service":"tidalconnect","title":"","artist":"","album":"","albumart":"/albumart","uri":"","icon":"fa fa-spinner","trackType":"tidal","codec":"","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"","channels":2,"random":false,"repeat":false,"repeatSingle":false} Apr 23 21:10:24 sibermusic volumio[2782]: verbose: CURRENT POSITION 0 Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreStateMachine::syncState stateService stop Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreStateMachine::syncState currentStatus stop Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreStateMachine::pushState Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreCommandRouter::volumioPushState Apr 23 21:10:24 sibermusic volumio[2782]: info: MRS: Pushing multiroomSync output update for this device Apr 23 21:10:24 sibermusic volumio[2782]: info: MRS: Pushing multiroomSync output Apr 23 21:10:24 sibermusic volumio[2782]: info: No code Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreStateMachine::pushState Apr 23 21:10:24 sibermusic volumio[2782]: info: CoreCommandRouter::volumioPushState Apr 23 21:10:24 sibermusic volumio[2782]: info: MRS: Pushing multiroomSync output update for this device Apr 23 21:10:24 sibermusic volumio[2782]: info: MRS: Pushing multiroomSync output Apr 23 21:10:24 sibermusic volumio[2782]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.h0PZQsB39AURSlylidLe37OavVF3.88dd99399252828aa992fa9b2610eee3.state.status' Apr 23 21:10:24 sibermusic volumio[2782]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.h0PZQsB39AURSlylidLe37OavVF3.88dd99399252828aa992fa9b2610eee3.state.status' Apr 23 21:10:24 sibermusic volumio[2782]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.h0PZQsB39AURSlylidLe37OavVF3.88dd99399252828aa992fa9b2610eee3.state.status' Apr 23 21:10:24 sibermusic volumio[2782]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.h0PZQsB39AURSlylidLe37OavVF3.88dd99399252828aa992fa9b2610eee3.state.status' Apr 23 21:10:24 sibermusic volumio[2782]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.h0PZQsB39AURSlylidLe37OavVF3.88dd99399252828aa992fa9b2610eee3.state.status' Apr 23 21:10:24 sibermusic volumio[2782]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.h0PZQsB39AURSlylidLe37OavVF3.88dd99399252828aa992fa9b2610eee3.state.status' Apr 23 21:10:25 sibermusic volumio[2782]: info: Discovery: Started advertising with name: sibermusic Apr 23 21:10:26 sibermusic volumio[2782]: compat.c: read() failed: Resource temporarily unavailable Apr 23 21:10:26 sibermusic volumio[2782]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 23 21:10:26 sibermusic volumio[2782]: Error: dns service error: unknown Apr 23 21:10:26 sibermusic volumio[2782]: at MDNSService.self.watcher.callback (/volumio/node_modules/mdns/lib/mdns_service.js:18:40) { Apr 23 21:10:26 sibermusic volumio[2782]: errorCode: -65537 Apr 23 21:10:26 sibermusic volumio[2782]: } Apr 23 21:10:26 sibermusic volumio[2782]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 23 21:10:26 sibermusic sudo[3753]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-04-23 21:09' Apr 23 21:10:26 sibermusic sudo[3753]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="77459d3da1093d939f1a501571c373c95e4a2652" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="0da3792b433b4daf69b90315de2841f333f7f716" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue Apr 22 11:07:15 UTC 2025" VOLUMIO_VERSION="0.058" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="cdc65c6dbdd6f51850072894d2c25614"