-- Logs begin at Sat 2025-03-08 04:47:27 CET, end at Thu 2025-03-13 11:05:39 CET. --
Mar 13 11:04:02 player volumio[663]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin multiroom
Mar 13 11:04:02 player sudo[1199]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -rf /tmp/multiroom
Mar 13 11:04:02 player sudo[1199]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:04:02 player sudo[1199]: pam_unix(sudo:session): session closed for user root
Mar 13 11:04:02 player volumio[663]: info: MRS: MultiRoom plugin initialized
Mar 13 11:04:02 player volumio[663]: info: MRS: STOPPING SNAPCLIENT
Mar 13 11:04:02 player volumio[663]: info: MRS: Snap server stop
Mar 13 11:04:02 player volumio[663]: info: MRS: STOPPING volumioStreaming
Mar 13 11:04:02 player sudo[1215]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapclient
Mar 13 11:04:02 player sudo[1215]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:04:02 player sudo[1217]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioSnapserver
Mar 13 11:04:02 player sudo[1217]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:04:02 player volumio[663]: info: [MyVolumio PluginManager] Loading plugin "metavolumio"...
Mar 13 11:04:02 player sudo[1223]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/*
Mar 13 11:04:02 player sudo[1223]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:04:02 player sudo[1223]: pam_unix(sudo:session): session closed for user root
Mar 13 11:04:02 player sudo[1215]: pam_unix(sudo:session): session closed for user root
Mar 13 11:04:02 player sudo[1217]: pam_unix(sudo:session): session closed for user root
Mar 13 11:04:02 player sudo[1221]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumioStreaming
Mar 13 11:04:02 player sudo[1221]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:04:02 player volumio[663]: info: [MyVolumio PluginManager] Loading plugin "manifestui"...
Mar 13 11:04:02 player volumio[663]: info: [MyVolumio PluginManager] Loading plugin "cd_controller"...
Mar 13 11:04:02 player sudo[1221]: pam_unix(sudo:session): session closed for user root
Mar 13 11:04:02 player volumio[663]: info: [MyVolumio PluginManager] Loading plugin "smart_inputs"...
Mar 13 11:04:02 player volumio[663]: info: [MyVolumio PluginManager] Loading plugin "hi_res_audio"...
Mar 13 11:04:03 player volumio[663]: info: [MyVolumio PluginManager] Applying required configuration parameters for plugin hi_res_audio
Mar 13 11:04:03 player volumio[663]: info: [MyVolumio PluginManager] Loading plugin "tidal"...
Mar 13 11:04:03 player volumio[663]: info: [MyVolumio PluginManager] Loading plugin "qobuz"...
Mar 13 11:04:03 player volumio[663]: info: [MyVolumio PluginManager] Loading plugin "tidalconnect"...
Mar 13 11:04:03 player volumio[663]: info: Preparing to generate the ALSA configuration file
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getHwuuid
Mar 13 11:04:03 player volumio[663]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf
Mar 13 11:04:03 player volumio[663]: info: Reading ALSA contributions from plugins.
Mar 13 11:04:03 player volumio[663]: info: Successfully Updated MyVolumio device
Mar 13 11:04:03 player volumio[663]: info:
Mar 13 11:04:03 player volumio[663]: ---------------------------- MPD announces state update: player
Mar 13 11:04:03 player volumio[663]: info: ControllerMpd::getState
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::sendMpdCommand status
Mar 13 11:04:03 player volumio[663]: info:
Mar 13 11:04:03 player volumio[663]: ---------------------------- MPD announces state update: player
Mar 13 11:04:03 player volumio[663]: info: ControllerMpd::getState
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::sendMpdCommand status
Mar 13 11:04:03 player volumio[663]: info:
Mar 13 11:04:03 player volumio[663]: ---------------------------- MPD announces state update: player
Mar 13 11:04:03 player volumio[663]: info: ControllerMpd::getState
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::sendMpdCommand status
Mar 13 11:04:03 player volumio[663]: info: MRS: Removed streaming files
Mar 13 11:04:03 player volumio[663]: info: MRS: volumioStreaming STOPPED
Mar 13 11:04:03 player volumio[663]: info: MRS: SNAPSERVER STOPPED
Mar 13 11:04:03 player volumio[663]: info: MRS: SNAPCLIENT STOPPED
Mar 13 11:04:03 player volumio[663]: info:
Mar 13 11:04:03 player volumio[663]: ---------------------------- MPD announces system playlist update
Mar 13 11:04:03 player volumio[663]: info: Ignoring MPD Status Update
Mar 13 11:04:03 player volumio[663]: info:
Mar 13 11:04:03 player volumio[663]: ---------------------------- MPD announces state update: player
Mar 13 11:04:03 player volumio[663]: info: ControllerMpd::getState
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::sendMpdCommand status
Mar 13 11:04:03 player volumio[663]: info: sendMpdCommand status took 45 milliseconds
Mar 13 11:04:03 player volumio[663]: info: sendMpdCommand status took 43 milliseconds
Mar 13 11:04:03 player volumio[663]: info: sendMpdCommand status took 40 milliseconds
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::parseState
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::parseState
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::parseState
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 13 11:04:03 player volumio[663]: info:
Mar 13 11:04:03 player volumio[663]: ---------------------------- MPD announces system playlist update
Mar 13 11:04:03 player volumio[663]: info: Ignoring MPD Status Update
Mar 13 11:04:03 player volumio[663]: info:
Mar 13 11:04:03 player volumio[663]: ---------------------------- MPD announces state update: player
Mar 13 11:04:03 player volumio[663]: info: ControllerMpd::getState
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::sendMpdCommand status
Mar 13 11:04:03 player volumio[663]: info:
Mar 13 11:04:03 player volumio[663]: ---------------------------- MPD announces system playlist update
Mar 13 11:04:03 player volumio[663]: info: Ignoring MPD Status Update
Mar 13 11:04:03 player volumio[663]: info:
Mar 13 11:04:03 player volumio[663]: ---------------------------- MPD announces state update: player
Mar 13 11:04:03 player volumio[663]: info: ControllerMpd::getState
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::sendMpdCommand status
Mar 13 11:04:03 player volumio[663]: info: ------------------------------ 66ms
Mar 13 11:04:03 player volumio[663]: info: sendMpdCommand status took 63 milliseconds
Mar 13 11:04:03 player volumio[663]: info: sendMpdCommand playlistinfo took 53 milliseconds
Mar 13 11:04:03 player volumio[663]: info: sendMpdCommand playlistinfo took 53 milliseconds
Mar 13 11:04:03 player volumio[663]: info: sendMpdCommand playlistinfo took 52 milliseconds
Mar 13 11:04:03 player volumio[663]: info: ------------------------------ 49ms
Mar 13 11:04:03 player volumio[663]: info: sendMpdCommand status took 28 milliseconds
Mar 13 11:04:03 player volumio[663]: info: ------------------------------ 26ms
Mar 13 11:04:03 player volumio[663]: info: sendMpdCommand status took 22 milliseconds
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::parseState
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::parseTrackInfo
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::parseTrackInfo
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::parseTrackInfo
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::parseState
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::parseState
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 13 11:04:03 player volumio[663]: info: ControllerMpd::pushState
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::servicePushState
Mar 13 11:04:03 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:04:03 player volumio[663]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5107,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Infos und Playlist auch im Netz: 1LIVEDIGGI.de","artist":"1Livediggi, Westdeutscher Rundfunk Koeln","album":null,"uri":"http://wdr-1live-diggi.icecastssl.wdr.de/wdr/1live/diggi/mp3/128/stream.mp3?aggregator=tunein","trackType":""}
Mar 13 11:04:03 player volumio[663]: verbose: CURRENT POSITION 0
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::syncState stateService play
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::syncState currentStatus stop
Mar 13 11:04:03 player volumio[663]: info: ControllerMpd::pushState
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::servicePushState
Mar 13 11:04:03 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:04:03 player volumio[663]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5107,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Infos und Playlist auch im Netz: 1LIVEDIGGI.de","artist":"1Livediggi, Westdeutscher Rundfunk Koeln","album":null,"uri":"http://wdr-1live-diggi.icecastssl.wdr.de/wdr/1live/diggi/mp3/128/stream.mp3?aggregator=tunein","trackType":""}
Mar 13 11:04:03 player volumio[663]: verbose: CURRENT POSITION 0
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::syncState stateService play
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::syncState currentStatus play
Mar 13 11:04:03 player volumio[663]: info: Received an update from plugin. extracting info from payload
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:04:03 player volumio[663]: info: ControllerMpd::pushState
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::servicePushState
Mar 13 11:04:03 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:04:03 player volumio[663]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5107,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Infos und Playlist auch im Netz: 1LIVEDIGGI.de","artist":"1Livediggi, Westdeutscher Rundfunk Koeln","album":null,"uri":"http://wdr-1live-diggi.icecastssl.wdr.de/wdr/1live/diggi/mp3/128/stream.mp3?aggregator=tunein","trackType":""}
Mar 13 11:04:03 player volumio[663]: verbose: CURRENT POSITION 0
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::syncState stateService play
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::syncState currentStatus play
Mar 13 11:04:03 player volumio[663]: info: Received an update from plugin. extracting info from payload
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:04:03 player volumio[663]: info: ------------------------------ 184ms
Mar 13 11:04:03 player volumio[663]: info: ------------------------------ 226ms
Mar 13 11:04:03 player volumio[663]: info: ------------------------------ 224ms
Mar 13 11:04:03 player volumio[663]: info: sendMpdCommand playlistinfo took 257 milliseconds
Mar 13 11:04:03 player volumio[663]: info: sendMpdCommand playlistinfo took 252 milliseconds
Mar 13 11:04:03 player volumio[663]: info: sendMpdCommand playlistinfo took 250 milliseconds
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::parseTrackInfo
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::parseTrackInfo
Mar 13 11:04:03 player volumio[663]: verbose: ControllerMpd::parseTrackInfo
Mar 13 11:04:03 player volumio[663]: info: ControllerMpd::pushState
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::servicePushState
Mar 13 11:04:03 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:04:03 player volumio[663]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5107,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Infos und Playlist auch im Netz: 1LIVEDIGGI.de","artist":"1Livediggi, Westdeutscher Rundfunk Koeln","album":null,"uri":"http://wdr-1live-diggi.icecastssl.wdr.de/wdr/1live/diggi/mp3/128/stream.mp3?aggregator=tunein","trackType":""}
Mar 13 11:04:03 player volumio[663]: verbose: CURRENT POSITION 0
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::syncState stateService play
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::syncState currentStatus play
Mar 13 11:04:03 player volumio[663]: info: Received an update from plugin. extracting info from payload
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:04:03 player volumio[663]: info: ControllerMpd::pushState
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::servicePushState
Mar 13 11:04:03 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:04:03 player volumio[663]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5233,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Infos und Playlist auch im Netz: 1LIVEDIGGI.de","artist":"1Livediggi, Westdeutscher Rundfunk Koeln","album":null,"uri":"http://wdr-1live-diggi.icecastssl.wdr.de/wdr/1live/diggi/mp3/128/stream.mp3?aggregator=tunein","trackType":""}
Mar 13 11:04:03 player volumio[663]: verbose: CURRENT POSITION 0
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::syncState stateService play
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::syncState currentStatus play
Mar 13 11:04:03 player volumio[663]: info: Received an update from plugin. extracting info from payload
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:04:03 player volumio[663]: info: ControllerMpd::pushState
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::servicePushState
Mar 13 11:04:03 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:04:03 player volumio[663]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5233,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"Infos und Playlist auch im Netz: 1LIVEDIGGI.de","artist":"1Livediggi, Westdeutscher Rundfunk Koeln","album":null,"uri":"http://wdr-1live-diggi.icecastssl.wdr.de/wdr/1live/diggi/mp3/128/stream.mp3?aggregator=tunein","trackType":""}
Mar 13 11:04:03 player volumio[663]: verbose: CURRENT POSITION 0
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::syncState stateService play
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::syncState currentStatus play
Mar 13 11:04:03 player volumio[663]: info: Received an update from plugin. extracting info from payload
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:04:03 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:04:03 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:04:04 player volumio[663]: info: ------------------------------ 458ms
Mar 13 11:04:04 player volumio[663]: info: ------------------------------ 437ms
Mar 13 11:04:04 player volumio[663]: info: ------------------------------ 415ms
Mar 13 11:04:04 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
Mar 13 11:04:04 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
Mar 13 11:04:04 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
Mar 13 11:04:04 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
Mar 13 11:04:04 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
Mar 13 11:04:04 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
Mar 13 11:04:04 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
Mar 13 11:04:04 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
Mar 13 11:04:04 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
Mar 13 11:04:04 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25
Mar 13 11:04:04 player volumio[663]: info: Asound.conf file written
Mar 13 11:04:04 player sudo[1269]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service
Mar 13 11:04:04 player sudo[1269]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:04:04 player sudo[1272]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf
Mar 13 11:04:04 player sudo[1272]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:04:04 player sudo[1272]: pam_unix(sudo:session): session closed for user root
Mar 13 11:04:04 player systemd[1]: Started MyVolumio SSH Tunnel.
Mar 13 11:04:04 player sudo[1269]: pam_unix(sudo:session): session closed for user root
Mar 13 11:04:04 player volumio[663]: info: Output device has changed, restarting MPD
Mar 13 11:04:04 player autossh[1277]: port set to 0, monitoring disabled
Mar 13 11:04:04 player autossh[1277]: starting ssh (count 1)
Mar 13 11:04:04 player autossh[1277]: ssh child pid is 1281
Mar 13 11:04:04 player sudo[1282]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Mar 13 11:04:04 player sudo[1282]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:04:04 player volumio[663]: info: Output device has changed, restarting Shairport Sync
Mar 13 11:04:04 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 13 11:04:04 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 13 11:04:04 player sudo[1282]: pam_unix(sudo:session): session closed for user root
Mar 13 11:04:04 player sudo[1284]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Mar 13 11:04:04 player sudo[1284]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:04:04 player volumio[663]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Mar 13 11:04:04 player volumio[663]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Mar 13 11:04:04 player systemd[1]: Stopping Music Player Daemon...
Mar 13 11:04:04 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 13 11:04:04 player systemd[1]: mpd.service: Succeeded.
Mar 13 11:04:04 player systemd[1]: Stopped Music Player Daemon.
Mar 13 11:04:04 player volumio[663]: info: [MyVolumio PluginManager] Starting plugin audio_interface.bluetooth
Mar 13 11:04:04 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Mar 13 11:04:04 player volumio[663]: info: [MyVolumio PluginManager] Starting plugin audio_interface.multiroom
Mar 13 11:04:04 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , pushMultiRoomStatus
Mar 13 11:04:04 player systemd[1]: Starting Music Player Daemon...
Mar 13 11:04:04 player volumio[663]: info: MRS: Pushing multiroomSync output for this device
Mar 13 11:04:04 player volumio[663]: info: MRS: Pushing multiroomSync output
Mar 13 11:04:04 player volumio[663]: info: Adding audio output:
Mar 13 11:04:04 player volumio[663]: info: Adding audio output:
Mar 13 11:04:04 player sudo[1294]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/hciconfig hci0 name Player
Mar 13 11:04:04 player sudo[1294]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:04:04 player volumio[663]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration
Mar 13 11:04:04 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 13 11:04:04 player volumio[663]: info: [MyVolumio PluginManager] Starting plugin miscellanea.metavolumio
Mar 13 11:04:04 player volumio[663]: info: Adding METAVOLUMIO REST API Endpoints
Mar 13 11:04:04 player volumio[663]: info: Adding metavolumio REST Endpoint for plugin: miscellanea/metavolumio
Mar 13 11:04:04 player volumio[663]: info: Adding getSimilarArtists REST Endpoint for plugin: miscellanea/metavolumio
Mar 13 11:04:04 player volumio[663]: info: Adding getSimilarAlbums REST Endpoint for plugin: miscellanea/metavolumio
Mar 13 11:04:04 player volumio[663]: info: Adding getSimilarTracks REST Endpoint for plugin: miscellanea/metavolumio
Mar 13 11:04:04 player volumio[663]: info: [MyVolumio PluginManager] Starting plugin miscellanea.manifestui
Mar 13 11:04:04 player volumio[663]: info: [MyVolumio PluginManager] Starting plugin music_service.cd_controller
Mar 13 11:04:04 player volumio[663]: info: [MyVolumio PluginManager] Plugin cd_controller disabled by user. Not starting
Mar 13 11:04:04 player volumio[663]: info: [MyVolumio PluginManager] Starting plugin music_service.smart_inputs
Mar 13 11:04:04 player volumio[663]: info: Adding inputs REST Endpoints
Mar 13 11:04:04 player volumio[663]: info: Adding scanAudioInputs REST Endpoint for plugin: music_service/smart_inputs
Mar 13 11:04:04 player volumio[663]: info: Scanning Audio Inputs
Mar 13 11:04:04 player sudo[1292]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Mar 13 11:04:04 player sudo[1292]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:04:04 player sudo[1292]: pam_unix(sudo:session): session closed for user root
Mar 13 11:04:04 player volumio[663]: info: Checking against Known Cards name
Mar 13 11:04:04 player volumio[663]: info: Adding Server instance for streaming
Mar 13 11:04:04 player volumio[663]: info: [MyVolumio PluginManager] Starting plugin music_service.hi_res_audio
Mar 13 11:04:04 player kernel: Bluetooth: Core ver 2.22
Mar 13 11:04:04 player kernel: NET: Registered PF_BLUETOOTH protocol family
Mar 13 11:04:04 player kernel: Bluetooth: HCI device and connection manager initialized
Mar 13 11:04:04 player kernel: Bluetooth: HCI socket layer initialized
Mar 13 11:04:04 player kernel: Bluetooth: L2CAP socket layer initialized
Mar 13 11:04:04 player kernel: Bluetooth: SCO socket layer initialized
Mar 13 11:04:04 player volumio[663]: error: Hi Res Audio Failed Login: Missing Login Data
Mar 13 11:04:04 player sudo[1294]: pam_unix(sudo:session): session closed for user root
Mar 13 11:04:04 player volumio[663]: info: Adding HIGHRESAUDIO REST API Endpoints
Mar 13 11:04:04 player volumio[663]: info: Adding getStreamUrlhi_res_audio REST Endpoint for plugin: music_service/hi_res_audio
Mar 13 11:04:04 player volumio[663]: info: [MyVolumio PluginManager] Starting plugin music_service.tidal
Mar 13 11:04:05 player volumio[663]: info: [MyVolumio PluginManager] Starting plugin music_service.qobuz
Mar 13 11:04:05 player volumio[663]: info: [MyVolumio PluginManager] Starting plugin music_service.tidalconnect
Mar 13 11:04:05 player volumio[663]: info: [MyVolumio PluginManager] Plugin tidalconnect disabled by user. Not starting
Mar 13 11:04:05 player volumio[663]: info: Stopping AccessToken refresher cron
Mar 13 11:04:05 player volumio[663]: info: AccessToken refresher cron started
Mar 13 11:04:05 player volumio[663]: info: Stopping AccessToken refresher cron for QOBUZ
Mar 13 11:04:05 player volumio[663]: info: AccessToken refresher cron started for QOBUZ
Mar 13 11:04:05 player volumio[663]: info: Adding TIDAL REST API Endpoints
Mar 13 11:04:05 player volumio[663]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal
Mar 13 11:04:05 player volumio[663]: info: Adding QOBUZ REST API Endpoints
Mar 13 11:04:05 player volumio[663]: info: Adding getStreamUrlqobuz REST Endpoint for plugin: music_service/qobuz
Mar 13 11:04:05 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Mar 13 11:04:05 player volumio[663]: error: Cannot set new Bluetooth Name : Error: Command failed: /usr/bin/sudo /bin/hciconfig hci0 name 'Player'
Mar 13 11:04:05 player volumio[663]: Can't get device info: No such device
Mar 13 11:04:05 player volumio[663]: info: MPD Permissions set
Mar 13 11:04:05 player volumio[663]: info: Remote SSH Started
Mar 13 11:04:05 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 13 11:04:05 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 13 11:04:05 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Mar 13 11:04:05 player volumio[663]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6
Mar 13 11:04:05 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 13 11:04:05 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 13 11:04:05 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 13 11:04:05 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 13 11:04:05 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 13 11:04:05 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 13 11:04:05 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 13 11:04:05 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 13 11:04:06 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 13 11:04:06 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 13 11:04:06 player volumio[663]: [Metrics] CommandRouter: 52s 275.40ms
Mar 13 11:04:06 player volumio[663]: info: CoreCommandRouter::volumiosetStartupVolume
Mar 13 11:04:06 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 13 11:04:06 player volumio[663]: info: VolumeController:: Setting startup Volume 30
Mar 13 11:04:06 player volumio[663]: info: VolumeController::SetAlsaVolume30
Mar 13 11:04:06 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Mar 13 11:04:06 player volumio[663]: info: CoreCommandRouter::Close All Modals sent
Mar 13 11:04:06 player volumio[663]: info: CoreCommandRouter::Close All Modals sent
Mar 13 11:04:06 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:04:06 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 13 11:04:06 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:04:06 player volumio[663]: info: MRS: Pushing multiroomSync output update for this device
Mar 13 11:04:06 player volumio[663]: info: MRS: Pushing multiroomSync output
Mar 13 11:04:06 player volumio[663]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7
Mar 13 11:04:06 player volumio-remote-updater[461]: No test mode
Mar 13 11:04:06 player volumio-remote-updater[461]: No alpha test mode
Mar 13 11:04:06 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Mar 13 11:04:06 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30
Mar 13 11:04:06 player volumio[663]: SPOTIFY: SPOTIFY VOLUME 25
Mar 13 11:04:06 player volumio[663]: SPOTIFY: VOLUMIO VOLUME 30
Mar 13 11:04:06 player volumio[663]: SPOTIFY: DELTA VOLUME ENOUGH: true
Mar 13 11:04:06 player volumio[663]: info: Setting Spotify Volume from Volumio: 30
Mar 13 11:04:06 player volumio[663]: info: Starting Shairport Sync
Mar 13 11:04:06 player volumio[663]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
Mar 13 11:04:07 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Mar 13 11:04:07 player volumio[663]: info: CoreCommandRouter::volumioGetState
Mar 13 11:04:07 player sudo[1317]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Mar 13 11:04:07 player sudo[1317]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:04:07 player volumio[663]: info: CoreCommandRouter::volumioGetState
Mar 13 11:04:07 player systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver...
Mar 13 11:04:07 player systemd[1]: shairport-sync.service: Succeeded.
Mar 13 11:04:07 player systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.
Mar 13 11:04:07 player systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
Mar 13 11:04:07 player sudo[1317]: pam_unix(sudo:session): session closed for user root
Mar 13 11:04:07 player volumio[663]: info: Shairport-Sync Started
Mar 13 11:04:07 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Mar 13 11:04:07 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Mar 13 11:04:07 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Mar 13 11:04:07 player sudo[1325]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service
Mar 13 11:04:07 player sudo[1325]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:04:07 player systemd[1]: Started Volumio Bluetooth Module.
Mar 13 11:04:07 player sudo[1325]: pam_unix(sudo:session): session closed for user root
Mar 13 11:04:07 player sudo[1328]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod -R 777 /var/lib/bluetooth/*
Mar 13 11:04:07 player sudo[1328]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:04:08 player volumiobt[1327]: /bin/chmod: cannot access '/var/lib/bluetooth/*': No such file or directory
Mar 13 11:04:08 player sudo[1328]: pam_unix(sudo:session): session closed for user root
Mar 13 11:04:08 player volumio[663]: info: Volumio BT Module successfully started
Mar 13 11:04:08 player mpd[1305]: Mar 13 11:04 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Mar 13 11:04:08 player systemd[1]: Started Music Player Daemon.
Mar 13 11:04:08 player sudo[1284]: pam_unix(sudo:session): session closed for user root
Mar 13 11:04:08 player volumio[663]: error: updateQueue error: null
Mar 13 11:04:08 player volumio[663]: SPOTIFY: SETTING SPOTIFY VOLUME 30
Mar 13 11:04:08 player volumio[663]: info: Sending Spotify command with payload to local API: /player/volume
Mar 13 11:04:09 player sudo[1333]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/usr/bin/killall pulseaudio
Mar 13 11:04:09 player sudo[1333]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:04:09 player volumiobt[1327]: pulseaudio: no process found
Mar 13 11:04:09 player sudo[1333]: pam_unix(sudo:session): session closed for user root
Mar 13 11:04:09 player dbus-daemon[445]: [system] Activating via systemd: service name='org.freedesktop.RealtimeKit1' unit='rtkit-daemon.service' requested by ':1.16' (uid=1000 pid=1337 comm="/usr/bin/pulseaudio --high-priority=true ")
Mar 13 11:04:09 player systemd[1]: Starting RealtimeKit Scheduling Policy Service...
Mar 13 11:04:09 player volumio[663]: ------------------------------------ BT MESSAGE: BT STATUS: running
Mar 13 11:04:09 player dbus-daemon[445]: [system] Successfully activated service 'org.freedesktop.RealtimeKit1'
Mar 13 11:04:09 player rtkit-daemon[1338]: Successfully called chroot.
Mar 13 11:04:09 player rtkit-daemon[1338]: Successfully dropped privileges.
Mar 13 11:04:09 player systemd[1]: Started RealtimeKit Scheduling Policy Service.
Mar 13 11:04:09 player rtkit-daemon[1338]: Successfully limited resources.
Mar 13 11:04:09 player rtkit-daemon[1338]: Canary thread running.
Mar 13 11:04:09 player rtkit-daemon[1338]: Running.
Mar 13 11:04:09 player rtkit-daemon[1338]: Watchdog thread running.
Mar 13 11:04:09 player dbus-daemon[445]: [system] Activating via systemd: service name='org.freedesktop.PolicyKit1' unit='polkit.service' requested by ':1.17' (uid=0 pid=1338 comm="/usr/lib/rtkit/rtkit-daemon ")
Mar 13 11:04:09 player systemd[1]: Starting Authorization Manager...
Mar 13 11:04:09 player volumio[663]: ------------------------------------ BT MESSAGE: BT STATUS: running
Mar 13 11:04:09 player polkitd[1342]: started daemon version 0.105 using authority implementation `local' version `0.105'
Mar 13 11:04:09 player dbus-daemon[445]: [system] Successfully activated service 'org.freedesktop.PolicyKit1'
Mar 13 11:04:09 player systemd[1]: Started Authorization Manager.
Mar 13 11:04:09 player volumio[663]: info: MRS: Getting audio outputs on start
Mar 13 11:04:09 player volumio[663]: info: MRS: Requesting all other devices output
Mar 13 11:04:09 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 13 11:04:09 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Mar 13 11:04:09 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Mar 13 11:04:09 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Mar 13 11:04:09 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Mar 13 11:04:09 player volumio[663]: info: CoreCommandRouter::volumioGetBrowseSources
Mar 13 11:04:09 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 13 11:04:10 player dbus-daemon[445]: [system] Activating via systemd: service name='org.bluez' unit='dbus-org.bluez.service' requested by ':1.37' (uid=1000 pid=1337 comm="/usr/bin/pulseaudio --high-priority=true ")
Mar 13 11:04:10 player systemd[1]: Starting Bluetooth service...
Mar 13 11:04:10 player volumio[663]: ------------------------------------ BT MESSAGE: BT STATUS: running
Mar 13 11:04:10 player pulseaudio[1337]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11
Mar 13 11:04:10 player pulseaudio[1337]: Unable to contact D-Bus: org.freedesktop.DBus.Error.NotSupported: Unable to autolaunch a dbus-daemon without a $DISPLAY for X11
Mar 13 11:04:10 player volumiobt[1327]: Applying permissions
Mar 13 11:04:10 player volumiobt[1327]: Setting BT discoverable and pairable
Mar 13 11:04:10 player bluetoothd[1347]: Bluetooth daemon 5.50
Mar 13 11:04:10 player bluetoothd[1347]: Unknown key AutoConnectTimeout for group General in /etc/bluetooth/main.conf
Mar 13 11:04:10 player dbus-daemon[445]: [system] Successfully activated service 'org.bluez'
Mar 13 11:04:10 player systemd[1]: Started Bluetooth service.
Mar 13 11:04:10 player bluetoothd[1347]: Starting SDP server
Mar 13 11:04:10 player bluetoothd[1347]: Excluding (cli) sap
Mar 13 11:04:10 player kernel: Bluetooth: BNEP (Ethernet Emulation) ver 1.3
Mar 13 11:04:10 player kernel: Bluetooth: BNEP filters: protocol multicast
Mar 13 11:04:10 player kernel: Bluetooth: BNEP socket layer initialized
Mar 13 11:04:10 player bluetoothd[1347]: Bluetooth management interface 1.22 initialized
Mar 13 11:04:10 player dbus-daemon[445]: [system] Activating via systemd: service name='org.freedesktop.hostname1' unit='dbus-org.freedesktop.hostname1.service' requested by ':1.38' (uid=0 pid=1347 comm="/usr/lib/bluetooth/bluetoothd --noplugin=sap ")
Mar 13 11:04:10 player volumiobt[1327]: Agent registered
Mar 13 11:04:10 player volumiobt[1327]: [bluetooth]# -e power on
Mar 13 11:04:10 player volumiobt[1327]: Invalid command in menu main: -e
Mar 13 11:04:10 player volumiobt[1327]:
Mar 13 11:04:10 player volumiobt[1327]: Use "help" for a list of available commands in a menu.
Mar 13 11:04:10 player volumiobt[1327]: Use "menu " if you want to enter any submenu.
Mar 13 11:04:10 player volumiobt[1327]: Use "back" if you want to return to menu main.
Mar 13 11:04:10 player volumiobt[1327]: [bluetooth]# agent on
Mar 13 11:04:10 player volumiobt[1327]: Agent is already registered
Mar 13 11:04:10 player volumiobt[1327]: [bluetooth]# discoverable on
Mar 13 11:04:10 player volumiobt[1327]: No default controller available
Mar 13 11:04:10 player volumiobt[1327]: [bluetooth]# pairable on
Mar 13 11:04:10 player volumiobt[1327]: No default controller available
Mar 13 11:04:10 player volumiobt[1327]: [bluetooth]# agent NoInputNoOutput
Mar 13 11:04:10 player volumiobt[1327]: Agent is already registered
Mar 13 11:04:10 player volumiobt[1327]: [bluetooth]# default-agent
Mar 13 11:04:10 player volumiobt[1327]: [bluetooth]# quit
Mar 13 11:04:10 player pulseaudio[1337]: 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
Mar 13 11:04:10 player volumiobt[1327]: [59B blob data]
Mar 13 11:04:10 player systemd[1]: Starting Hostname Service...
Mar 13 11:04:10 player volumio[663]: ------------------------------------ BT MESSAGE: BT STATUS: running
Mar 13 11:04:10 player dbus-daemon[445]: [system] Successfully activated service 'org.freedesktop.hostname1'
Mar 13 11:04:10 player systemd[1]: Started Hostname Service.
Mar 13 11:04:12 player ntpd[617]: Soliciting pool server 185.252.140.125
Mar 13 11:04:12 player ntpd[617]: Soliciting pool server 157.90.24.29
Mar 13 11:04:13 player ntpd[617]: Soliciting pool server 162.159.200.1
Mar 13 11:04:13 player ntpd[617]: Soliciting pool server 144.76.43.40
Mar 13 11:04:13 player volumio[663]: info: BOOT COMPLETED
Mar 13 11:04:14 player ntpd[617]: Soliciting pool server 130.162.220.39
Mar 13 11:04:14 player ntpd[617]: Soliciting pool server 78.46.60.40
Mar 13 11:04:14 player ntpd[617]: Soliciting pool server 194.164.164.175
Mar 13 11:04:15 player ntpd[617]: Soliciting pool server 158.220.97.17
Mar 13 11:04:15 player ntpd[617]: Soliciting pool server 49.13.14.46
Mar 13 11:04:15 player ntpd[617]: Soliciting pool server 85.215.93.134
Mar 13 11:04:16 player ntpd[617]: Soliciting pool server 178.63.67.56
Mar 13 11:04:16 player ntpd[617]: Soliciting pool server 213.172.105.106
Mar 13 11:04:17 player ntpd[617]: Soliciting pool server 185.13.148.71
Mar 13 11:04:17 player ntpd[617]: Soliciting pool server 94.130.184.193
Mar 13 11:04:18 player ntpd[617]: Soliciting pool server 94.16.122.152
Mar 13 11:04:18 player ntpd[617]: Soliciting pool server 2a02:8106:21:9400::7
Mar 13 11:04:20 player ntpd[617]: receive: Unexpected origin timestamp 0xeb7d2c23.14f15aee does not match aorg 0000000000.00000000 from server@178.63.67.56 xmt 0xeb7d2c24.51ca5cde
Mar 13 11:04:20 player ntpd[617]: receive: Unexpected origin timestamp 0xeb7d2c23.14f9819b does not match aorg 0000000000.00000000 from server@49.13.14.46 xmt 0xeb7d2c24.51a9c6c9
Mar 13 11:04:20 player ntpd[617]: receive: Unexpected origin timestamp 0xeb7d2c23.1502a428 does not match aorg 0000000000.00000000 from server@185.252.140.125 xmt 0xeb7d2c24.51c35088
Mar 13 11:04:20 player ntpd[617]: receive: Unexpected origin timestamp 0xeb7d2c23.14f60d52 does not match aorg 0000000000.00000000 from server@85.215.93.134 xmt 0xeb7d2c24.5483f55a
Mar 13 11:04:30 player volumiossh-tunnel[1274]: Warning: Permanently added '[eu4.myvolumio.org]:2222,[167.172.103.77]:2222' (RSA) to the list of known hosts.
Mar 13 11:04:42 player systemd[1]: systemd-hostnamed.service: Succeeded.
Mar 13 11:04:56 player volumio[989]: ...........................................................................................................................................................................................................................................................................................++++
Mar 13 11:04:56 player volumio[989]: e is 65537 (0x010001)
Mar 13 11:04:56 player volumio[989]: writing RSA key
Mar 13 11:05:17 player volumio[663]: verbose: New Socket.io Connection to 192.168.100.29 from 192.168.100.216 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_4 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.4 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 8
Mar 13 11:05:17 player volumio[663]: info: CoreCommandRouter::volumioGetState
Mar 13 11:05:17 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Mar 13 11:05:17 player volumio[663]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom
Mar 13 11:05:17 player volumio[663]: info: Listing playlists
Mar 13 11:05:19 player sudo[1521]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Mar 13 11:05:19 player sudo[1521]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:05:19 player sudo[1521]: pam_unix(sudo:session): session closed for user root
Mar 13 11:05:19 player sudo[1523]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Mar 13 11:05:19 player sudo[1523]: pam_unix(sudo:session): session opened for user root by (uid=0)
Mar 13 11:05:19 player sudo[1523]: pam_unix(sudo:session): session closed for user root
Mar 13 11:05:19 player volumio[663]: verbose: New Socket.io Connection to 192.168.100.29 from 192.168.100.216 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_4 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/18.4 Mobile/15E148 Safari/604.1 Engine version: 3 Transport: polling Total Clients: 9
Mar 13 11:05:19 player volumio[663]: info: CoreCommandRouter::volumioGetVisibleSources
Mar 13 11:05:19 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 13 11:05:19 player volumio[663]: info: CoreCommandRouter::volumioGetState
Mar 13 11:05:19 player volumio[663]: info: CoreCommandRouter::volumioGetQueue
Mar 13 11:05:19 player volumio[663]: info: CoreStateMachine::getQueue
Mar 13 11:05:19 player volumio[663]: info: CorePlayQueue::getQueue
Mar 13 11:05:19 player volumio[663]: info: Listing playlists
Mar 13 11:05:19 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Mar 13 11:05:19 player volumio[663]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom
Mar 13 11:05:19 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Mar 13 11:05:19 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Mar 13 11:05:19 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Mar 13 11:05:19 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Mar 13 11:05:21 player volumio[663]: info: CoreCommandRouter::volumioStop
Mar 13 11:05:21 player volumio[663]: info: CoreStateMachine::stop
Mar 13 11:05:21 player volumio[663]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 13 11:05:21 player volumio[663]: info: CoreStateMachine::stPlaybackTimer
Mar 13 11:05:21 player volumio[663]: info: CoreStateMachine::updateTrackBlock
Mar 13 11:05:21 player volumio[663]: info: CorePlayQueue::getTrackBlock
Mar 13 11:05:21 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:05:21 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:05:21 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 13 11:05:21 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:05:21 player volumio[663]: info: MRS: Pushing multiroomSync output update for this device
Mar 13 11:05:21 player volumio[663]: info: MRS: Pushing multiroomSync output
Mar 13 11:05:21 player volumio[663]: info: CoreStateMachine::serviceStop
Mar 13 11:05:21 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:05:21 player volumio[663]: info: CoreCommandRouter::serviceStop
Mar 13 11:05:21 player volumio[663]: info: [1741860321522] ControllerWebradio::stop
Mar 13 11:05:21 player volumio[663]: verbose: ControllerMpd::sendMpdCommand stop
Mar 13 11:05:21 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30
Mar 13 11:05:21 player volumio[663]: info: sendMpdCommand stop took 65 milliseconds
Mar 13 11:05:28 player volumio[663]: info: VolumeController::SetAlsaVolume20
Mar 13 11:05:28 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:05:28 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:05:28 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 13 11:05:28 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:05:28 player volumio[663]: info: MRS: Pushing multiroomSync output update for this device
Mar 13 11:05:28 player volumio[663]: info: MRS: Pushing multiroomSync output
Mar 13 11:05:28 player volumio[663]: info: VolumeController::SetAlsaVolume30
Mar 13 11:05:28 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:05:28 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:05:28 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 13 11:05:28 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:05:28 player volumio[663]: info: MRS: Pushing multiroomSync output update for this device
Mar 13 11:05:28 player volumio[663]: info: MRS: Pushing multiroomSync output
Mar 13 11:05:28 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20
Mar 13 11:05:28 player volumio[663]: SPOTIFY: SPOTIFY VOLUME 30
Mar 13 11:05:28 player volumio[663]: SPOTIFY: VOLUMIO VOLUME 20
Mar 13 11:05:28 player volumio[663]: SPOTIFY: DELTA VOLUME ENOUGH: true
Mar 13 11:05:28 player volumio[663]: info: Setting Spotify Volume from Volumio: 20
Mar 13 11:05:28 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30
Mar 13 11:05:28 player volumio[663]: SPOTIFY: SPOTIFY VOLUME 20
Mar 13 11:05:28 player volumio[663]: SPOTIFY: VOLUMIO VOLUME 30
Mar 13 11:05:28 player volumio[663]: SPOTIFY: DELTA VOLUME ENOUGH: true
Mar 13 11:05:28 player volumio[663]: info: Setting Spotify Volume from Volumio: 30
Mar 13 11:05:29 player volumio[663]: info: VolumeController::SetAlsaVolume55
Mar 13 11:05:29 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:05:29 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:05:29 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 13 11:05:29 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:05:29 player volumio[663]: info: MRS: Pushing multiroomSync output update for this device
Mar 13 11:05:29 player volumio[663]: info: MRS: Pushing multiroomSync output
Mar 13 11:05:29 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55
Mar 13 11:05:29 player volumio[663]: SPOTIFY: SPOTIFY VOLUME 30
Mar 13 11:05:29 player volumio[663]: SPOTIFY: VOLUMIO VOLUME 55
Mar 13 11:05:29 player volumio[663]: SPOTIFY: DELTA VOLUME ENOUGH: true
Mar 13 11:05:29 player volumio[663]: info: Setting Spotify Volume from Volumio: 55
Mar 13 11:05:29 player volumio[663]: info: VolumeController::SetAlsaVolume75
Mar 13 11:05:29 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:05:29 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:05:29 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 13 11:05:29 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:05:29 player volumio[663]: info: MRS: Pushing multiroomSync output update for this device
Mar 13 11:05:29 player volumio[663]: info: MRS: Pushing multiroomSync output
Mar 13 11:05:29 player volumio[663]: info: VolumeController::SetAlsaVolume85
Mar 13 11:05:29 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:05:29 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:05:29 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 13 11:05:29 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:05:29 player volumio[663]: info: MRS: Pushing multiroomSync output update for this device
Mar 13 11:05:29 player volumio[663]: info: MRS: Pushing multiroomSync output
Mar 13 11:05:29 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75
Mar 13 11:05:29 player volumio[663]: SPOTIFY: SPOTIFY VOLUME 55
Mar 13 11:05:29 player volumio[663]: SPOTIFY: VOLUMIO VOLUME 75
Mar 13 11:05:29 player volumio[663]: SPOTIFY: DELTA VOLUME ENOUGH: true
Mar 13 11:05:29 player volumio[663]: info: Setting Spotify Volume from Volumio: 75
Mar 13 11:05:29 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 85
Mar 13 11:05:29 player volumio[663]: SPOTIFY: SPOTIFY VOLUME 75
Mar 13 11:05:29 player volumio[663]: SPOTIFY: VOLUMIO VOLUME 85
Mar 13 11:05:29 player volumio[663]: SPOTIFY: DELTA VOLUME ENOUGH: true
Mar 13 11:05:29 player volumio[663]: info: Setting Spotify Volume from Volumio: 85
Mar 13 11:05:29 player volumio[663]: info: VolumeController::SetAlsaVolume95
Mar 13 11:05:29 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:05:29 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:05:29 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 13 11:05:29 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:05:29 player volumio[663]: info: MRS: Pushing multiroomSync output update for this device
Mar 13 11:05:29 player volumio[663]: info: MRS: Pushing multiroomSync output
Mar 13 11:05:29 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95
Mar 13 11:05:29 player volumio[663]: SPOTIFY: SPOTIFY VOLUME 85
Mar 13 11:05:29 player volumio[663]: SPOTIFY: VOLUMIO VOLUME 95
Mar 13 11:05:29 player volumio[663]: SPOTIFY: DELTA VOLUME ENOUGH: true
Mar 13 11:05:29 player volumio[663]: info: Setting Spotify Volume from Volumio: 95
Mar 13 11:05:30 player volumio[663]: info: VolumeController::SetAlsaVolume50
Mar 13 11:05:30 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:05:30 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:05:30 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 13 11:05:30 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:05:30 player volumio[663]: info: MRS: Pushing multiroomSync output update for this device
Mar 13 11:05:30 player volumio[663]: info: MRS: Pushing multiroomSync output
Mar 13 11:05:30 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50
Mar 13 11:05:30 player volumio[663]: SPOTIFY: SPOTIFY VOLUME 95
Mar 13 11:05:30 player volumio[663]: SPOTIFY: VOLUMIO VOLUME 50
Mar 13 11:05:30 player volumio[663]: SPOTIFY: DELTA VOLUME ENOUGH: true
Mar 13 11:05:30 player volumio[663]: info: Setting Spotify Volume from Volumio: 50
Mar 13 11:05:31 player volumio[663]: info: VolumeController::SetAlsaVolume50
Mar 13 11:05:31 player volumio[663]: info: CoreStateMachine::pushState
Mar 13 11:05:31 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:05:31 player volumio[663]: info: CoreCommandRouter::volumioPushState
Mar 13 11:05:31 player volumio[663]: info: MRS: Pushing multiroomSync output update for this device
Mar 13 11:05:31 player volumio[663]: info: MRS: Pushing multiroomSync output
Mar 13 11:05:31 player volumio[663]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50
Mar 13 11:05:32 player volumio[663]: SPOTIFY: SETTING SPOTIFY VOLUME 50
Mar 13 11:05:32 player volumio[663]: info: Sending Spotify command with payload to local API: /player/volume
Mar 13 11:05:37 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Mar 13 11:05:37 player volumio[663]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Mar 13 11:05:37 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Mar 13 11:05:37 player volumio[663]: info: Received Get System Version
Mar 13 11:05:37 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 13 11:05:37 player volumio[663]: info: Received Get System Info
Mar 13 11:05:37 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 13 11:05:37 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 13 11:05:37 player volumio[663]: info: Discovery: Getting this device information
Mar 13 11:05:37 player volumio[663]: info: CoreCommandRouter::volumioGetState
Mar 13 11:05:37 player volumio[663]: info: CorePlayQueue::getTrack 0
Mar 13 11:05:37 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 13 11:05:38 player volumio[663]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPause
Mar 13 11:05:38 player volumio[663]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPause] in plugin multiroom
Mar 13 11:05:38 player volumio[663]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 13 11:05:38 player volumio[663]: TypeError: Cannot read property 'then' of undefined
Mar 13 11:05:38 player volumio[663]: at outputs.audioOutputPause (/volumio/app/plugins/audio_interface/outputs/index.js:417:9)
Mar 13 11:05:38 player volumio[663]: at CoreCommandRouter.audioOutputPause (/volumio/app/index.js:2290:30)
Mar 13 11:05:38 player volumio[663]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1462:26)
Mar 13 11:05:38 player volumio[663]: at Socket.emit (events.js:315:20)
Mar 13 11:05:38 player volumio[663]: at /volumio/node_modules/socket.io/lib/socket.js:528:12
Mar 13 11:05:38 player volumio[663]: at processTicksAndRejections (internal/process/task_queues.js:75:11)
Mar 13 11:05:38 player volumio[663]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 13 11:05:39 player sudo[1579]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-13 11:04
Mar 13 11:05:39 player sudo[1579]: 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="147953990fca4aa103a8f90538ef56fb0454638c"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 11:42:54 AM CET"
VOLUMIO_VERSION="3.795"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="4049a67f1c09d4a94e033ba35a80a144"