-- Logs begin at Sat 2024-11-30 19:36:41 CET, end at Sat 2024-11-30 19:39:42 CET. -- Nov 30 19:38:00 volumio volumio[1013]: Cannot compose Albumart path Nov 30 19:38:01 volumio volumio[1013]: info: MyVolumio login type: Token Nov 30 19:38:01 volumio volumio[1013]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Nov 30 19:38:02 volumio volumio[1013]: info: MyVolumio token set successfully Nov 30 19:38:02 volumio volumio[1013]: info: MYVOLUMIO: Adding device Nov 30 19:38:02 volumio volumio[1013]: info: MYVOLUMIO: Evaluating Server Nov 30 19:38:02 volumio volumio[1013]: info: MyVolumio Plan changed: premium Nov 30 19:38:02 volumio volumio[1013]: info: [MyVolumio PluginManager] Subscribed plan changed to premium Nov 30 19:38:02 volumio volumio[1013]: info: Removing browser output: myVolumio user plan is not superstar Nov 30 19:38:02 volumio volumio[1013]: info: Removing audio output: Nov 30 19:38:02 volumio volumio[1013]: info: MYVOLUMIO: Adding device Nov 30 19:38:02 volumio volumio[1013]: info: MYVOLUMIO: Evaluating Server Nov 30 19:38:02 volumio volumio[1013]: info: Remote config written successfully Nov 30 19:38:02 volumio volumio[1013]: info: Starting Tunnel 1 Nov 30 19:38:02 volumio volumio[1013]: info: Starting Tunnel Connection Checker Nov 30 19:38:02 volumio volumio[1013]: info: Completed starting MyVolumio Plugin Nov 30 19:38:02 volumio volumio[1013]: info: MYVolumio Device enabled Nov 30 19:38:02 volumio volumio[1013]: info: [MyVolumio PluginManager] Device activated, enabling myvolumio plugins... Nov 30 19:38:02 volumio volumio[1013]: info: MyVolumio status changed Nov 30 19:38:02 volumio volumio[1013]: info: Streaming services startup Nov 30 19:38:02 volumio volumio[1013]: info: Starting Streaming Daemon Nov 30 19:38:02 volumio sudo[1350]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Nov 30 19:38:02 volumio sudo[1350]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 19:38:02 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Nov 30 19:38:02 volumio sudo[1350]: pam_unix(sudo:session): session closed for user root Nov 30 19:38:02 volumio volumio[1013]: error: [MyVolumio PluginManager] Cache data is invalid! Nov 30 19:38:02 volumio volumio[1013]: error: Cannot start Volumio Streaming Daemon Nov 30 19:38:02 volumio volumio[1013]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Nov 30 19:38:02 volumio volumio[1013]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Nov 30 19:38:03 volumio volumio[1013]: info: Setting Geolocation for MyVolumio to eu5 Nov 30 19:38:03 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 30 19:38:03 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 30 19:38:03 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 30 19:38:03 volumio volumio[1013]: info: [MyVolumio PluginManager] Loading plugin "bluetooth"... Nov 30 19:38:03 volumio volumio[1013]: info: [1732991883432] Starting BluetoothController Nov 30 19:38:03 volumio volumio[1013]: info: [MyVolumio PluginManager] Loading plugin "multiroom"... Nov 30 19:38:04 volumio volumio[1013]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom Nov 30 19:38:04 volumio sudo[1353]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom Nov 30 19:38:04 volumio sudo[1353]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 19:38:04 volumio sudo[1353]: pam_unix(sudo:session): session closed for user root Nov 30 19:38:04 volumio volumio[1013]: info: MRS: MultiRoom plugin initialized Nov 30 19:38:04 volumio volumio[1013]: info: MRS: STOPPING SNAPCLIENT Nov 30 19:38:04 volumio volumio[1013]: info: MRS: Snap server stop Nov 30 19:38:04 volumio volumio[1267]: ......................................................................................................................++++ Nov 30 19:38:04 volumio sudo[1369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient Nov 30 19:38:04 volumio sudo[1369]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 19:38:04 volumio volumio[1013]: info: MRS: STOPPING volumioStreaming Nov 30 19:38:04 volumio sudo[1372]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver Nov 30 19:38:04 volumio sudo[1372]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 19:38:04 volumio sudo[1375]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming Nov 30 19:38:04 volumio sudo[1375]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 19:38:04 volumio sudo[1372]: pam_unix(sudo:session): session closed for user root Nov 30 19:38:04 volumio sudo[1369]: pam_unix(sudo:session): session closed for user root Nov 30 19:38:04 volumio sudo[1375]: pam_unix(sudo:session): session closed for user root Nov 30 19:38:04 volumio volumio[1013]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"... Nov 30 19:38:04 volumio sudo[1378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Nov 30 19:38:04 volumio sudo[1378]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 19:38:04 volumio sudo[1378]: pam_unix(sudo:session): session closed for user root Nov 30 19:38:04 volumio volumio[1013]: info: [MyVolumio PluginManager] Loading plugin "manifestui"... Nov 30 19:38:04 volumio volumio[1013]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"... Nov 30 19:38:04 volumio volumio[1013]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"... Nov 30 19:38:04 volumio volumio[1013]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"... Nov 30 19:38:04 volumio volumio[1013]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio Nov 30 19:38:04 volumio volumio[1013]: info: [MyVolumio PluginManager] Loading plugin "tidal"... Nov 30 19:38:04 volumio volumio[1013]: info: [MyVolumio PluginManager] Loading plugin "qobuz"... Nov 30 19:38:04 volumio volumio[1013]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"... Nov 30 19:38:04 volumio volumio[1013]: info: Preparing to generate the ALSA configuration file Nov 30 19:38:04 volumio volumio[1013]: info: Updating MyVolumio device info Nov 30 19:38:04 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 30 19:38:04 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 30 19:38:04 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 30 19:38:04 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid Nov 30 19:38:04 volumio volumio[1013]: info: Successfully Added MyVolumio device Nov 30 19:38:04 volumio volumio[1013]: info: Setting Geolocation for MyVolumio to eu9 Nov 30 19:38:04 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 30 19:38:04 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 30 19:38:04 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 30 19:38:04 volumio volumio[1013]: info: MRS: Removed streaming files Nov 30 19:38:04 volumio volumio[1013]: info: MRS: volumioStreaming STOPPED Nov 30 19:38:04 volumio volumio[1013]: info: MRS: SNAPSERVER STOPPED Nov 30 19:38:04 volumio volumio[1013]: info: MRS: SNAPCLIENT STOPPED Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 30 19:38:05 volumio volumio[1013]: info: Discovery: Getting this device information Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::volumioGetState Nov 30 19:38:05 volumio volumio[1013]: info: CorePlayQueue::getTrack 0 Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 30 19:38:05 volumio volumio[1013]: info: Asound.conf file unchanged, so no further update is needed Nov 30 19:38:05 volumio volumio[1013]: info: Output device has changed, restarting MPD Nov 30 19:38:05 volumio sudo[1381]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 30 19:38:05 volumio sudo[1381]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 19:38:05 volumio volumio[1013]: info: Output device has changed, restarting Shairport Sync Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 30 19:38:05 volumio sudo[1381]: pam_unix(sudo:session): session closed for user root Nov 30 19:38:05 volumio sudo[1384]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 30 19:38:05 volumio sudo[1384]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 19:38:05 volumio systemd[1]: Stopping Music Player Daemon... Nov 30 19:38:05 volumio volumio[1013]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 30 19:38:05 volumio volumio[1013]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 30 19:38:05 volumio systemd[1]: mpd.service: Succeeded. Nov 30 19:38:05 volumio systemd[1]: Stopped Music Player Daemon. Nov 30 19:38:05 volumio volumio[1013]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 30 19:38:05 volumio volumio[1013]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom Nov 30 19:38:05 volumio volumio[1013]: info: [MyVolumio PluginManager] Plugin multiroom disabled by user. Not starting Nov 30 19:38:05 volumio volumio[1013]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio Nov 30 19:38:05 volumio volumio[1013]: info: Adding METAVOLUMIO REST API Endpoints Nov 30 19:38:05 volumio volumio[1013]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio Nov 30 19:38:05 volumio volumio[1013]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio Nov 30 19:38:05 volumio volumio[1013]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio Nov 30 19:38:05 volumio volumio[1013]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio Nov 30 19:38:05 volumio volumio[1013]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui Nov 30 19:38:05 volumio volumio[1013]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller Nov 30 19:38:05 volumio volumio[1013]: info: [MyVolumio PluginManager] Plugin cd_controller disabled by user. Not starting Nov 30 19:38:05 volumio volumio[1013]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs Nov 30 19:38:05 volumio volumio[1013]: info: Adding inputs REST Endpoints Nov 30 19:38:05 volumio volumio[1013]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs Nov 30 19:38:05 volumio volumio[1013]: info: Scanning Audio Inputs Nov 30 19:38:05 volumio sudo[1393]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Volumio Nov 30 19:38:05 volumio sudo[1393]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 19:38:05 volumio systemd[1]: Starting Music Player Daemon... Nov 30 19:38:05 volumio sudo[1393]: pam_unix(sudo:session): session closed for user root Nov 30 19:38:05 volumio volumio[1013]: info: Checking against Known Cards name Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 30 19:38:05 volumio volumio[1013]: info: [1732991885242] CoreMusicLibrary::Adding element HiFiBerry ADC Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 30 19:38:05 volumio volumio[1013]: Cannot find translation for source HiFiBerry ADC Nov 30 19:38:05 volumio volumio[1013]: info: Checking against Known Cards name Nov 30 19:38:05 volumio volumio[1013]: info: Adding Server instance for streaming Nov 30 19:38:05 volumio volumio[1013]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio Nov 30 19:38:05 volumio volumio[1013]: error: Hi Res Audio Failed Login: Missing Login Data Nov 30 19:38:05 volumio volumio[1013]: info: Adding HIGHRESAUDIO REST API Endpoints Nov 30 19:38:05 volumio volumio[1013]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio Nov 30 19:38:05 volumio volumio[1013]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal Nov 30 19:38:05 volumio volumio[1013]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz Nov 30 19:38:05 volumio volumio[1013]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect Nov 30 19:38:05 volumio volumio[1013]: info: [MyVolumio PluginManager] Plugin tidalconnect disabled by user. Not starting Nov 30 19:38:05 volumio volumio[1013]: info: Stopping AccessToken refresher cron Nov 30 19:38:05 volumio sudo[1391]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 30 19:38:05 volumio sudo[1391]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 19:38:05 volumio volumio[1013]: info: AccessToken refresher cron started Nov 30 19:38:05 volumio volumio[1013]: info: Stopping AccessToken refresher cron for QOBUZ Nov 30 19:38:05 volumio sudo[1391]: pam_unix(sudo:session): session closed for user root Nov 30 19:38:05 volumio volumio[1013]: info: AccessToken refresher cron started for QOBUZ Nov 30 19:38:05 volumio volumio[1013]: info: Adding TIDAL REST API Endpoints Nov 30 19:38:05 volumio volumio[1013]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Nov 30 19:38:05 volumio volumio[1013]: info: Adding QOBUZ REST API Endpoints Nov 30 19:38:05 volumio volumio[1013]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz Nov 30 19:38:05 volumio volumio[1013]: [Metrics] CommandRouter: 26s 653.09ms Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::volumiosetStartupVolume Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::Close All Modals sent Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::Close All Modals sent Nov 30 19:38:05 volumio kernel: bcm2835-i2s fe203000.i2s: I2S SYNC error! Nov 30 19:38:05 volumio volumio[1013]: info: Bluetooth name changed to Volumio Nov 30 19:38:05 volumio volumio[1013]: info: MPD Permissions set Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 30 19:38:05 volumio volumio[1013]: info: Starting Shairport Sync Nov 30 19:38:05 volumio sudo[1406]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 30 19:38:05 volumio sudo[1406]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 19:38:05 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 30 19:38:05 volumio systemd[1]: shairport-sync.service: Succeeded. Nov 30 19:38:05 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 30 19:38:05 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 30 19:38:05 volumio sudo[1406]: pam_unix(sudo:session): session closed for user root Nov 30 19:38:05 volumio volumio[1013]: info: Shairport-Sync Started Nov 30 19:38:05 volumio volumio[1013]: info: Successfully Updated MyVolumio device Nov 30 19:38:05 volumio volumio[1013]: info: Successfully Added MyVolumio device Nov 30 19:38:05 volumio volumio[1013]: info: Updating MyVolumio device info Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 30 19:38:05 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 30 19:38:06 volumio mpd[1398]: Nov 30 19:38 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 30 19:38:06 volumio volumio[1013]: info: Successfully Updated MyVolumio device Nov 30 19:38:06 volumio systemd[1]: Started Music Player Daemon. Nov 30 19:38:06 volumio sudo[1384]: pam_unix(sudo:session): session closed for user root Nov 30 19:38:06 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Nov 30 19:38:06 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 30 19:38:06 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Nov 30 19:38:06 volumio volumio[1013]: error: updateQueue error: null Nov 30 19:38:07 volumio sudo[1418]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Nov 30 19:38:07 volumio sudo[1418]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 19:38:07 volumio systemd[1]: Started MyVolumio SSH Tunnel. Nov 30 19:38:07 volumio sudo[1418]: pam_unix(sudo:session): session closed for user root Nov 30 19:38:07 volumio volumio[1013]: info: Remote SSH Started Nov 30 19:38:07 volumio autossh[1421]: port set to 0, monitoring disabled Nov 30 19:38:07 volumio autossh[1421]: starting ssh (count 1) Nov 30 19:38:07 volumio autossh[1421]: ssh child pid is 1424 Nov 30 19:38:07 volumio volumio[1013]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Nov 30 19:38:07 volumio volumio[1013]: info: CoreCommandRouter::volumioGetState Nov 30 19:38:07 volumio volumio[1013]: info: CorePlayQueue::getTrack 0 Nov 30 19:38:07 volumio volumiossh-tunnel[1420]: Warning: Permanently added '[eu9.myvolumio.org]:2222,[164.92.213.40]:2222' (RSA) to the list of known hosts. Nov 30 19:38:08 volumio sudo[1426]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Nov 30 19:38:08 volumio sudo[1426]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 19:38:08 volumio systemd[1]: Started Volumio Bluetooth Module. Nov 30 19:38:08 volumio sudo[1426]: pam_unix(sudo:session): session closed for user root Nov 30 19:38:08 volumio volumio[1013]: info: Volumio BT Module successfully started Nov 30 19:38:08 volumio sudo[1429]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/* Nov 30 19:38:08 volumio sudo[1429]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 19:38:08 volumio volumiobt[1428]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory Nov 30 19:38:08 volumio sudo[1429]: pam_unix(sudo:session): session closed for user root Nov 30 19:38:09 volumio systemd[1]: systemd-timedated.service: Succeeded. Nov 30 19:38:09 volumio sudo[1434]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio Nov 30 19:38:09 volumio sudo[1434]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 19:38:09 volumio volumiobt[1428]: pulseaudio: no process found Nov 30 19:38:09 volumio sudo[1434]: pam_unix(sudo:session): session closed for user root Nov 30 19:38:09 volumio dbus-daemon[654]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.19' (uid=1000 pid=1438 comm="/usr/bin/pulseaudio --high-priority=true ") Nov 30 19:38:09 volumio systemd[1]: Starting RealtimeKit Scheduling Policy Service... Nov 30 19:38:09 volumio volumio[1013]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 30 19:38:09 volumio dbus-daemon[654]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1' Nov 30 19:38:09 volumio systemd[1]: Started RealtimeKit Scheduling Policy Service. Nov 30 19:38:09 volumio rtkit-daemon[1439]: Successfully called chroot. Nov 30 19:38:09 volumio rtkit-daemon[1439]: Successfully dropped privileges. Nov 30 19:38:09 volumio rtkit-daemon[1439]: Successfully limited resources. Nov 30 19:38:09 volumio rtkit-daemon[1439]: Running. Nov 30 19:38:09 volumio rtkit-daemon[1439]: Canary thread running. Nov 30 19:38:09 volumio rtkit-daemon[1439]: Watchdog thread running. Nov 30 19:38:09 volumio dbus-daemon[654]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.20' (uid=0 pid=1439 comm="/usr/lib/rtkit/rtkit-daemon ") Nov 30 19:38:09 volumio systemd[1]: Starting Authorization Manager... Nov 30 19:38:09 volumio volumio[1013]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 30 19:38:09 volumio polkitd[1443]: started daemon version 0.105 using authority implementation `local' version `0.105' Nov 30 19:38:09 volumio dbus-daemon[654]: [system] Successfully activated service 'org.freedesktop.PolicyKit1' Nov 30 19:38:09 volumio systemd[1]: Started Authorization Manager. Nov 30 19:38:09 volumio pulseaudio[1438]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Nov 30 19:38:09 volumio pulseaudio[1438]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11 Nov 30 19:38:09 volumio bluetoothd[766]: Endpoint registered: sender=:1.40 path=/MediaEndpoint/A2DPSource Nov 30 19:38:09 volumio pulseaudio[1438]: Failed to register as a handsfree audio agent with ofono: org.freedesktop.DBus.Error.ServiceUnknown: The name org.ofono was not provided by any .service files Nov 30 19:38:09 volumio volumiobt[1428]: Applying permissions Nov 30 19:38:09 volumio volumiobt[1428]: Setting BT discoverable and pairable Nov 30 19:38:09 volumio bluetoothd[766]: Endpoint registered: sender=:1.40 path=/MediaEndpoint/A2DPSink Nov 30 19:38:09 volumio kernel: Bluetooth: RFCOMM TTY layer initialized Nov 30 19:38:09 volumio kernel: Bluetooth: RFCOMM socket layer initialized Nov 30 19:38:09 volumio kernel: Bluetooth: RFCOMM ver 1.11 Nov 30 19:38:09 volumio volumiobt[1428]: [CHG] Controller DC:A6:32:4C:0B:08 UUIDs: 00001112-0000-1000-8000-00805f9b34fb Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [91B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [55B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [117B blob data] Nov 30 19:38:09 volumio volumiobt[1428]: [bluetooth]# -e power on Nov 30 19:38:09 volumio volumiobt[1428]: Invalid command in menu main: -e Nov 30 19:38:09 volumio volumiobt[1428]: Nov 30 19:38:09 volumio volumiobt[1428]: Use "help" for a list of available commands in a menu. Nov 30 19:38:09 volumio volumiobt[1428]: Use "menu " if you want to enter any submenu. Nov 30 19:38:09 volumio volumiobt[1428]: Use "back" if you want to return to menu main. Nov 30 19:38:09 volumio volumiobt[1428]: [bluetooth]# agent on Nov 30 19:38:09 volumio volumiobt[1428]: Agent is already registered Nov 30 19:38:09 volumio volumiobt[1428]: [bluetooth]# discoverable on Nov 30 19:38:09 volumio volumiobt[1428]: [bluetooth]# pairable on Nov 30 19:38:09 volumio volumiobt[1428]: [bluetooth]# agent NoInputNoOutput Nov 30 19:38:09 volumio volumiobt[1428]: Agent is already registered Nov 30 19:38:09 volumio volumiobt[1428]: [bluetooth]# default-agent Nov 30 19:38:09 volumio volumiobt[1428]: [bluetooth]# quit Nov 30 19:38:09 volumio volumiobt[1428]: [59B blob data] Nov 30 19:38:09 volumio volumio[1267]: .........................................................++++ Nov 30 19:38:09 volumio volumio[1267]: e is 65537 (0x010001) Nov 30 19:38:09 volumio volumio[1267]: writing RSA key Nov 30 19:38:10 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 30 19:38:10 volumio volumio[1013]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Nov 30 19:38:10 volumio volumio[1013]: info: CoreCommandRouter::volumioGetState Nov 30 19:38:10 volumio volumio[1013]: info: CorePlayQueue::getTrack 0 Nov 30 19:38:12 volumio volumio[1013]: info: BOOT COMPLETED Nov 30 19:38:13 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 30 19:38:13 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 30 19:38:13 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 30 19:38:13 volumio volumio-remote-updater[650]: No test mode Nov 30 19:38:13 volumio volumio-remote-updater[650]: No alpha test mode Nov 30 19:38:13 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Nov 30 19:38:14 volumio volumio[1013]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Nov 30 19:38:14 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Nov 30 19:38:15 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 30 19:38:15 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 30 19:38:15 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Nov 30 19:38:15 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Nov 30 19:38:15 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Nov 30 19:38:15 volumio volumio[1013]: info: CoreCommandRouter::volumioGetBrowseSources Nov 30 19:38:15 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 30 19:38:24 volumio ntpd[779]: Soliciting pool server 194.177.34.116 Nov 30 19:38:25 volumio ntpd[779]: Soliciting pool server 185.123.84.51 Nov 30 19:38:26 volumio ntpd[779]: Soliciting pool server 162.159.200.123 Nov 30 19:38:26 volumio ntpd[779]: Soliciting pool server 212.227.232.161 Nov 30 19:38:26 volumio ntpd[779]: Soliciting pool server 79.92.188.216 Nov 30 19:38:27 volumio ntpd[779]: Soliciting pool server 129.151.225.244 Nov 30 19:38:27 volumio ntpd[779]: Soliciting pool server 54.36.61.42 Nov 30 19:38:27 volumio ntpd[779]: Soliciting pool server 82.64.81.218 Nov 30 19:38:28 volumio ntpd[779]: Soliciting pool server 82.64.247.11 Nov 30 19:38:28 volumio ntpd[779]: Soliciting pool server 37.59.63.125 Nov 30 19:38:29 volumio ntpd[779]: Soliciting pool server 2001:41d0:305:2100::621 Nov 30 19:38:30 volumio ntpd[779]: Soliciting pool server 151.80.168.4 Nov 30 19:38:31 volumio ntpd[779]: Soliciting pool server 82.65.235.151 Nov 30 19:38:31 volumio ntpd[779]: receive: Unexpected origin timestamp 0xeaf5da27.3df6fccd does not match aorg 0000000000.00000000 from server@162.159.200.123 xmt 0xeaf5da27.e858efda Nov 30 19:38:31 volumio ntpd[779]: receive: Unexpected origin timestamp 0xeaf5da27.3df6030c does not match aorg 0000000000.00000000 from server@79.92.188.216 xmt 0xeaf5da27.e872b888 Nov 30 19:38:31 volumio ntpd[779]: receive: Unexpected origin timestamp 0xeaf5da27.3df7ede7 does not match aorg 0000000000.00000000 from server@185.123.84.51 xmt 0xeaf5da27.e8a65e0a Nov 30 19:38:31 volumio ntpd[779]: receive: Unexpected origin timestamp 0xeaf5da27.3df2cd37 does not match aorg 0000000000.00000000 from server@82.64.81.218 xmt 0xeaf5da27.eb88bcee Nov 30 19:38:32 volumio ntpd[779]: Soliciting pool server 5.39.80.51 Nov 30 19:38:33 volumio ntpd[779]: Soliciting pool server 51.195.104.188 Nov 30 19:38:34 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 30 19:38:34 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 30 19:38:34 volumio volumio[1013]: info: Discovery: Getting this device information Nov 30 19:38:34 volumio volumio[1013]: info: CoreCommandRouter::volumioGetState Nov 30 19:38:34 volumio volumio[1013]: info: CorePlayQueue::getTrack 0 Nov 30 19:38:34 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 30 19:38:34 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 30 19:38:34 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 30 19:39:04 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 30 19:39:04 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 30 19:39:04 volumio volumio[1013]: info: Discovery: Getting this device information Nov 30 19:39:04 volumio volumio[1013]: info: CoreCommandRouter::volumioGetState Nov 30 19:39:04 volumio volumio[1013]: info: CorePlayQueue::getTrack 0 Nov 30 19:39:04 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 30 19:39:34 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 30 19:39:34 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 30 19:39:34 volumio volumio[1013]: info: Discovery: Getting this device information Nov 30 19:39:34 volumio volumio[1013]: info: CoreCommandRouter::volumioGetState Nov 30 19:39:34 volumio volumio[1013]: info: CorePlayQueue::getTrack 0 Nov 30 19:39:34 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 30 19:39:37 volumio volumio[1013]: info: Retrieving Cloud Streaming UI Nov 30 19:39:37 volumio volumio[1013]: info: Getting Tidal Cloud Configuration Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 30 19:39:37 volumio volumio[1013]: info: Getting Qobuz Cloud Configuration Nov 30 19:39:37 volumio volumio[1013]: info: Asking plugin for UI Config Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 30 19:39:37 volumio volumio[1013]: info: Getting Spotify Cloud Configuration Nov 30 19:39:37 volumio volumio[1013]: info: Asking plugin for UI Config Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 30 19:39:37 volumio volumio[1013]: info: Saving Spotify Acccount Nov 30 19:39:37 volumio volumio[1013]: info: Got it Nov 30 19:39:37 volumio volumio[1013]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Nov 30 19:39:37 volumio volumio[1013]: info: Got Tidal Cloud Configuration Nov 30 19:39:37 volumio volumio[1013]: info: Got it Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::volumioGetBrowseSources Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::volumioGetBrowseSources Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::volumioGetBrowseSources Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 30 19:39:37 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Nov 30 19:39:38 volumio volumio[1013]: info: Disabling MyMusic plugin upnp Nov 30 19:39:38 volumio sudo[1701]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service Nov 30 19:39:38 volumio sudo[1701]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 30 19:39:38 volumio systemd[1]: Stopping UPnP Renderer front-end to MPD... Nov 30 19:39:38 volumio volumio[1013]: error: Upnp client error: Error: This socket has been ended by the other party Nov 30 19:39:38 volumio volumio[1013]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 30 19:39:41 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Nov 30 19:39:42 volumio volumio[1013]: info: Enabling MyMusic plugin upnp Nov 30 19:39:42 volumio volumio[1013]: info: Enabling plugin upnp Nov 30 19:39:42 volumio volumio[1013]: info: Loading plugin "upnp"... Nov 30 19:39:42 volumio volumio[1013]: info: [1732991982174] Starting Upmpd Daemon Nov 30 19:39:42 volumio volumio[1013]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Nov 30 19:39:42 volumio volumio[1013]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 30 19:39:42 volumio volumio[1013]: Error: listen EADDRINUSE: address already in use :::6599 Nov 30 19:39:42 volumio volumio[1013]: at Server.setupListenHandle [as _listen2] (net.js:1318:16) Nov 30 19:39:42 volumio volumio[1013]: at listenInCluster (net.js:1366:12) Nov 30 19:39:42 volumio volumio[1013]: at Server.listen (net.js:1452:7) Nov 30 19:39:42 volumio volumio[1013]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) Nov 30 19:39:42 volumio volumio[1013]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) Nov 30 19:39:42 volumio volumio[1013]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Nov 30 19:39:42 volumio volumio[1013]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Nov 30 19:39:42 volumio volumio[1013]: at processTicksAndRejections (internal/process/task_queues.js:75:11) { Nov 30 19:39:42 volumio volumio[1013]: code: 'EADDRINUSE', Nov 30 19:39:42 volumio volumio[1013]: errno: -98, Nov 30 19:39:42 volumio volumio[1013]: syscall: 'listen', Nov 30 19:39:42 volumio volumio[1013]: address: '::', Nov 30 19:39:42 volumio volumio[1013]: port: 6599 Nov 30 19:39:42 volumio volumio[1013]: } Nov 30 19:39:42 volumio volumio[1013]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 30 19:39:42 volumio sudo[1726]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-30 19:38 Nov 30 19:39:42 volumio sudo[1726]: 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"