-- Logs begin at Sun 2024-10-06 23:32:40 CEST, end at Sun 2024-10-06 23:38:25 CEST. -- Oct 06 23:37:02 sweetspot volumiossh-tunnel[1807]: Warning: Permanently added '[eu4.myvolumio.org]:2222,[167.172.103.77]:2222' (RSA) to the list of known hosts. Oct 06 23:37:25 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 06 23:37:25 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 06 23:37:25 sweetspot volumio[954]: info: Discovery: Getting this device information Oct 06 23:37:25 sweetspot volumio[954]: info: CoreCommandRouter::volumioGetState Oct 06 23:37:25 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 06 23:37:55 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 06 23:37:55 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 06 23:37:55 sweetspot volumio[954]: info: Discovery: Getting this device information Oct 06 23:37:55 sweetspot volumio[954]: info: CoreCommandRouter::volumioGetState Oct 06 23:37:55 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 06 23:37:56 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 06 23:38:06 sweetspot volumio[954]: info: CoreCommandRouter::volumioNext Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::next Oct 06 23:38:06 sweetspot volumio[954]: info: [1728250686242] ControllerTidal::next Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::next Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::stop Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::stPlaybackTimer Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::updateTrackBlock Oct 06 23:38:06 sweetspot volumio[954]: info: CorePlayQueue::getTrackBlock Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::pushState Oct 06 23:38:06 sweetspot volumio[954]: info: CorePlayQueue::getTrack 4 Oct 06 23:38:06 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 06 23:38:06 sweetspot volumio[954]: info: CoreCommandRouter::volumioPushState Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::serviceStop Oct 06 23:38:06 sweetspot volumio[954]: info: CorePlayQueue::getTrack 4 Oct 06 23:38:06 sweetspot volumio[954]: info: CoreCommandRouter::serviceStop Oct 06 23:38:06 sweetspot volumio[954]: info: [1728250686249] ControllerTidal::stop Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 06 23:38:06 sweetspot volumio[954]: info: ControllerMpd::stop Oct 06 23:38:06 sweetspot volumio[954]: verbose: ControllerMpd::sendMpdCommand stop Oct 06 23:38:06 sweetspot volumio[954]: info: sendMpdCommand stop took 11 milliseconds Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::play index undefined Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 06 23:38:06 sweetspot volumio[954]: info: CorePlayQueue::getTrack 5 Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::startPlaybackTimer Oct 06 23:38:06 sweetspot volumio[954]: info: CorePlayQueue::getTrack 5 Oct 06 23:38:06 sweetspot volumio[954]: info: [1728250686266] ControllerTidal::clearAddPlayTrack Oct 06 23:38:06 sweetspot volumio[954]: info: Getting stream with soundQuality LOSSLESS Oct 06 23:38:06 sweetspot volumio[954]: verbose: ControllerMpd::sendMpdCommand stop Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::updateTrackBlock Oct 06 23:38:06 sweetspot volumio[954]: info: CorePlayQueue::getTrackBlock Oct 06 23:38:06 sweetspot volumio[954]: info: sendMpdCommand stop took 1 milliseconds Oct 06 23:38:06 sweetspot volumio[954]: verbose: ControllerMpd::sendMpdCommand clear Oct 06 23:38:06 sweetspot volumio[954]: info: Oct 06 23:38:06 sweetspot volumio[954]: ---------------------------- MPD announces system playlist update Oct 06 23:38:06 sweetspot volumio[954]: info: Ignoring MPD Status Update Oct 06 23:38:06 sweetspot volumio[954]: info: sendMpdCommand clear took 1 milliseconds Oct 06 23:38:06 sweetspot volumio[954]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/63269353&soundQuality=LOSSLESS" Oct 06 23:38:06 sweetspot volumio[954]: error: updateQueue error: null Oct 06 23:38:06 sweetspot volumio[954]: info: Oct 06 23:38:06 sweetspot volumio[954]: ---------------------------- MPD announces system playlist update Oct 06 23:38:06 sweetspot volumio[954]: info: Ignoring MPD Status Update Oct 06 23:38:06 sweetspot volumio[954]: info: ------------------------------ 3ms Oct 06 23:38:06 sweetspot volumio[954]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/63269353&soundQuality=LOSSLESS" took 2 milliseconds Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 06 23:38:06 sweetspot volumio[954]: verbose: ControllerMpd::sendMpdCommand play Oct 06 23:38:06 sweetspot volumio[954]: info: ------------------------------ 2ms Oct 06 23:38:06 sweetspot volumio[954]: info: sendMpdCommand play took 1 milliseconds Oct 06 23:38:06 sweetspot volumio[954]: STREAMING PROXY: Handling url /?data=tidal://song/63269353&soundQuality=LOSSLESS Oct 06 23:38:06 sweetspot volumio[954]: info: Executing endpoint getStreamUrltidal Oct 06 23:38:06 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Oct 06 23:38:06 sweetspot volumio[954]: info: getStreamUrl took 340 milliseconds Oct 06 23:38:06 sweetspot volumio[954]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKwgDEidlNzYwOWVlNTAzYmJiOTdhNTU4Mjk1NmZkNGVkOTdlZF82MS5tcDQ/0.flac?Expires=1728254286&Signature=LjlVV1nBOlKswGOsIHfe7MmOr~YK6W6DrCJW1r2CRslUTegOA-rVMAdR7CPSQeuCuIc9J045rUkHtZM6mCTPPSZt~CdB27lHfKNNG9G4pKuBfwh155sFjOZCxoiZy6JAR4U-ofGmxjy~eRYwT-B2nnF0vokSCjrZKzs95LL42Dotjk2ssuPDtu4-oJTy6z3ovEiwIUYmppClK5bM1wVY2VseUvQtdK4vyHDcDNBZw9SOJX~DXyrnGTTs~UjbGHhRffrCj4FjkSvesuRF4JyAfeazEfdqb33GjoT1Y61FefEZ0e5cwisjcO3DgDTsNZg6R6ff2kGM8DuPuJZMtVUgEw__&Key-Pair-Id=K14LZCZ9QUI4JL Oct 06 23:38:06 sweetspot volumio[954]: STREAMING PROXY: Response: 200, length: 46615156 Oct 06 23:38:06 sweetspot volumio[954]: info: Oct 06 23:38:06 sweetspot volumio[954]: ---------------------------- MPD announces state update: player Oct 06 23:38:06 sweetspot volumio[954]: info: ControllerMpd::getState Oct 06 23:38:06 sweetspot volumio[954]: verbose: ControllerMpd::sendMpdCommand status Oct 06 23:38:06 sweetspot volumio[954]: info: Oct 06 23:38:06 sweetspot volumio[954]: ---------------------------- MPD announces state update: player Oct 06 23:38:06 sweetspot volumio[954]: info: sendMpdCommand status took 21 milliseconds Oct 06 23:38:06 sweetspot volumio[954]: info: ControllerMpd::getState Oct 06 23:38:06 sweetspot volumio[954]: verbose: ControllerMpd::sendMpdCommand status Oct 06 23:38:06 sweetspot volumio[954]: verbose: ControllerMpd::parseState Oct 06 23:38:06 sweetspot volumio[954]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 06 23:38:06 sweetspot volumio[954]: info: sendMpdCommand status took 1 milliseconds Oct 06 23:38:06 sweetspot volumio[954]: info: sendMpdCommand playlistinfo took 1 milliseconds Oct 06 23:38:06 sweetspot volumio[954]: verbose: ControllerMpd::parseState Oct 06 23:38:06 sweetspot volumio[954]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 06 23:38:06 sweetspot volumio[954]: verbose: ControllerMpd::parseTrackInfo Oct 06 23:38:06 sweetspot volumio[954]: info: ControllerMpd::pushState Oct 06 23:38:06 sweetspot volumio[954]: info: CoreCommandRouter::servicePushState Oct 06 23:38:06 sweetspot volumio[954]: info: CorePlayQueue::getTrack 5 Oct 06 23:38:06 sweetspot volumio[954]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":420,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"63269353&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/63269353&soundQuality=LOSSLESS","trackType":"tidal"} Oct 06 23:38:06 sweetspot volumio[954]: verbose: CURRENT POSITION 5 Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::syncState stateService play Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::syncState currentStatus stop Oct 06 23:38:06 sweetspot volumio[954]: info: ------------------------------ 25ms Oct 06 23:38:06 sweetspot volumio[954]: info: sendMpdCommand playlistinfo took 2 milliseconds Oct 06 23:38:06 sweetspot volumio[954]: verbose: ControllerMpd::parseTrackInfo Oct 06 23:38:06 sweetspot volumio[954]: info: ControllerMpd::pushState Oct 06 23:38:06 sweetspot volumio[954]: info: CoreCommandRouter::servicePushState Oct 06 23:38:06 sweetspot volumio[954]: info: CorePlayQueue::getTrack 5 Oct 06 23:38:06 sweetspot volumio[954]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":420,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"63269353&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/63269353&soundQuality=LOSSLESS","trackType":"tidal"} Oct 06 23:38:06 sweetspot volumio[954]: verbose: CURRENT POSITION 5 Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::syncState stateService play Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::syncState currentStatus play Oct 06 23:38:06 sweetspot volumio[954]: info: Received an update from plugin. extracting info from payload Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::pushState Oct 06 23:38:06 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 06 23:38:06 sweetspot volumio[954]: info: CoreCommandRouter::volumioPushState Oct 06 23:38:06 sweetspot volumio[954]: info: CoreStateMachine::pushState Oct 06 23:38:06 sweetspot volumio[954]: info: CoreCommandRouter::volumioPushState Oct 06 23:38:06 sweetspot volumio[954]: info: ------------------------------ 33ms Oct 06 23:38:10 sweetspot volumio[954]: STREAMING PROXY: Client dropped request, destroying Oct 06 23:38:15 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 06 23:38:15 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 06 23:38:18 sweetspot volumio[954]: info: Enabling plugin fusiondsp Oct 06 23:38:18 sweetspot volumio[954]: info: Loading plugin "fusiondsp"... Oct 06 23:38:18 sweetspot volumio[954]: info: Applying required configuration parameters for plugin fusiondsp Oct 06 23:38:18 sweetspot volumio[954]: info: Preparing to generate the ALSA configuration file Oct 06 23:38:18 sweetspot volumio[954]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Oct 06 23:38:18 sweetspot volumio[954]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Oct 06 23:38:18 sweetspot volumio[954]: info: Reading ALSA contributions from plugins. Oct 06 23:38:18 sweetspot volumio[954]: info: Asound.conf file written Oct 06 23:38:18 sweetspot sudo[2149]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Oct 06 23:38:18 sweetspot sudo[2149]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:18 sweetspot sudo[2149]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:18 sweetspot volumio[954]: xcb_connection_has_error() returned true Oct 06 23:38:18 sweetspot volumio[954]: info: Output device has changed, restarting MPD Oct 06 23:38:18 sweetspot sudo[2154]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 06 23:38:18 sweetspot sudo[2154]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:18 sweetspot sudo[2154]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:19 sweetspot volumio[954]: info: Output device has changed, restarting Shairport Sync Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 23:38:19 sweetspot sudo[2157]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 06 23:38:19 sweetspot sudo[2157]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:19 sweetspot systemd[1]: Stopping Music Player Daemon... Oct 06 23:38:19 sweetspot volumio[954]: xcb_connection_has_error() returned true Oct 06 23:38:19 sweetspot volumio[954]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 06 23:38:19 sweetspot volumio[954]: xcb_connection_has_error() returned true Oct 06 23:38:19 sweetspot volumio[954]: [SpotifyConnect] Creating VLS config file Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot vtcs[1704]: [2024-10-06 23:38:19.057] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE Oct 06 23:38:19 sweetspot vtcs[1704]: [2024-10-06 23:38:19.057] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected Oct 06 23:38:19 sweetspot vtcs[1704]: [2024-10-06 23:38:19.057] [tisoc] [error] [SpkconServer.cpp:473] socket write error. fd=3 errorno=32 error=Broken pipe Oct 06 23:38:19 sweetspot systemd[1]: mpd.service: Succeeded. Oct 06 23:38:19 sweetspot systemd[1]: Stopped Music Player Daemon. Oct 06 23:38:19 sweetspot volumio[954]: info: PLUGIN START: fusiondsp Oct 06 23:38:19 sweetspot volumio[954]: info: Loading i18n strings for locale en Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Oct 06 23:38:19 sweetspot sudo[2164]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 06 23:38:19 sweetspot sudo[2164]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: FusionDsp - mixtype--------------------- Hardware Oct 06 23:38:19 sweetspot volumio[954]: info: Preparing to generate the ALSA configuration file Oct 06 23:38:19 sweetspot volumio[954]: info: Done. Oct 06 23:38:19 sweetspot volumio[954]: [SpotifyConnect] Restarting Vollibrespot Daemon Oct 06 23:38:19 sweetspot systemd[1]: Starting Music Player Daemon... Oct 06 23:38:19 sweetspot sudo[2167]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect.service Oct 06 23:38:19 sweetspot sudo[2167]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:19 sweetspot systemd[1]: Stopping Volumio Tidal Connect Service... Oct 06 23:38:19 sweetspot systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Oct 06 23:38:19 sweetspot systemd[1]: vtcs.service: Succeeded. Oct 06 23:38:19 sweetspot systemd[1]: Stopped Volumio Tidal Connect Service. Oct 06 23:38:19 sweetspot volumio[954]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Oct 06 23:38:19 sweetspot volumio[954]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Oct 06 23:38:19 sweetspot volumio[954]: info: Reading ALSA contributions from plugins. Oct 06 23:38:19 sweetspot volumio[954]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 06 23:38:19 sweetspot volumio[954]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 06 23:38:19 sweetspot volumio[954]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 06 23:38:19 sweetspot volumio[954]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 06 23:38:19 sweetspot sudo[2170]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 06 23:38:19 sweetspot sudo[2170]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:19 sweetspot volumio[954]: info: MPD Permissions set Oct 06 23:38:19 sweetspot sudo[2164]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot systemd[1]: Started Volspotconnect2 Daemon. Oct 06 23:38:19 sweetspot volumio[2173]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Oct 06 23:38:19 sweetspot volumio[2173]: Reading Config from "/tmp/volspotify.toml" Oct 06 23:38:19 sweetspot volumio[2173]: [Vollibrespot] : Using Alsa backend with device: volumio Oct 06 23:38:19 sweetspot sudo[2167]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:19 sweetspot sudo[2163]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 06 23:38:19 sweetspot sudo[2163]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:19 sweetspot sudo[2170]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot sudo[2163]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:19 sweetspot volumio[954]: [SpotifyConnect] Vollibrespot Daemon service restarted! Oct 06 23:38:19 sweetspot volumio[954]: info: Starting Shairport Sync Oct 06 23:38:19 sweetspot volumio[2173]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Uncategorized, message: "No such device" } Oct 06 23:38:19 sweetspot volumio[954]: info: Asound.conf file unchanged, so no further update is needed Oct 06 23:38:19 sweetspot volumio[954]: info: Output device has changed, restarting MPD Oct 06 23:38:19 sweetspot sudo[2183]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 06 23:38:19 sweetspot sudo[2183]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:19 sweetspot systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 06 23:38:19 sweetspot systemd[1]: shairport-sync.service: Succeeded. Oct 06 23:38:19 sweetspot systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 06 23:38:19 sweetspot systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 06 23:38:19 sweetspot sudo[2183]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:19 sweetspot volumio[954]: info: Output device has changed, restarting Shairport Sync Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 23:38:19 sweetspot sudo[2186]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 06 23:38:19 sweetspot sudo[2186]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:19 sweetspot sudo[2186]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:19 sweetspot sudo[2189]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 06 23:38:19 sweetspot sudo[2189]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:19 sweetspot systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Oct 06 23:38:19 sweetspot systemd[1]: mpd.service: Succeeded. Oct 06 23:38:19 sweetspot systemd[1]: Stopped Music Player Daemon. Oct 06 23:38:19 sweetspot volumio[954]: xcb_connection_has_error() returned true Oct 06 23:38:19 sweetspot volumio[954]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 06 23:38:19 sweetspot volumio[954]: xcb_connection_has_error() returned true Oct 06 23:38:19 sweetspot volumio[954]: [SpotifyConnect] Creating VLS config file Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: [SpotifyConnect] Restarting Vollibrespot Daemon Oct 06 23:38:19 sweetspot sudo[2199]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 06 23:38:19 sweetspot sudo[2199]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:19 sweetspot systemd[1]: Starting Music Player Daemon... Oct 06 23:38:19 sweetspot sudo[2202]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect.service Oct 06 23:38:19 sweetspot sudo[2202]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:19 sweetspot sudo[2199]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:19 sweetspot volumio[954]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 06 23:38:19 sweetspot volumio[954]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 06 23:38:19 sweetspot volumio[954]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 06 23:38:19 sweetspot volumio[954]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 06 23:38:19 sweetspot systemd[1]: Stopping Volspotconnect2 Daemon... Oct 06 23:38:19 sweetspot volumio[954]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 06 23:38:19 sweetspot systemd[1]: volspotconnect.service: Main process exited, code=killed, status=15/TERM Oct 06 23:38:19 sweetspot systemd[1]: volspotconnect.service: Succeeded. Oct 06 23:38:19 sweetspot systemd[1]: Stopped Volspotconnect2 Daemon. Oct 06 23:38:19 sweetspot volumio[954]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 06 23:38:19 sweetspot systemd[1]: Started Volspotconnect2 Daemon. Oct 06 23:38:19 sweetspot sudo[2202]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:19 sweetspot volumio[954]: error: Upnp client error: Error: This socket has been ended by the other party Oct 06 23:38:19 sweetspot volumio[954]: info: MPD Permissions set Oct 06 23:38:19 sweetspot volumio[954]: info: Shairport-Sync Started Oct 06 23:38:19 sweetspot sudo[2206]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Oct 06 23:38:19 sweetspot sudo[2206]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:19 sweetspot volumio[2207]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-05-31 Oct 06 23:38:19 sweetspot volumio[2207]: Reading Config from "/tmp/volspotify.toml" Oct 06 23:38:19 sweetspot volumio[2207]: [Vollibrespot] : Using Alsa backend with device: volumio Oct 06 23:38:19 sweetspot volumio[954]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 06 23:38:19 sweetspot volumio[954]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 06 23:38:19 sweetspot volumio[954]: [SpotifyConnect] Vollibrespot Daemon service restarted! Oct 06 23:38:19 sweetspot sudo[2197]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 06 23:38:19 sweetspot sudo[2197]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:19 sweetspot sudo[2197]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:19 sweetspot sudo[2206]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[2207]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Uncategorized, message: "No such device" } Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:19 sweetspot volumio[954]: info: Starting Shairport Sync Oct 06 23:38:19 sweetspot sudo[2218]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 06 23:38:19 sweetspot sudo[2218]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:19 sweetspot systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 06 23:38:19 sweetspot systemd[1]: shairport-sync.service: Succeeded. Oct 06 23:38:19 sweetspot systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 06 23:38:19 sweetspot volumio[954]: ------------------------------------ BT MESSAGE: BT STATUS: running Oct 06 23:38:19 sweetspot volumio[954]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Oct 06 23:38:19 sweetspot systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 06 23:38:19 sweetspot sudo[2218]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:19 sweetspot volumio[954]: info: Shairport-Sync Started Oct 06 23:38:20 sweetspot mpd[2211]: Oct 06 23:38 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 06 23:38:20 sweetspot systemd[1]: Started Music Player Daemon. Oct 06 23:38:20 sweetspot sudo[2189]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:20 sweetspot sudo[2157]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:20 sweetspot volumio[954]: error: MPD error: The expression evaluated to a falsy value: Oct 06 23:38:20 sweetspot volumio[954]: assert.ok(self.idling) Oct 06 23:38:20 sweetspot volumio[954]: error: The expression evaluated to a falsy value: Oct 06 23:38:20 sweetspot volumio[954]: assert.ok(self.idling) Oct 06 23:38:20 sweetspot volumio[954]: error: updateQueue error: null Oct 06 23:38:21 sweetspot volumio[954]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Oct 06 23:38:21 sweetspot volumio[954]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo Oct 06 23:38:21 sweetspot volumio[954]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Oct 06 23:38:21 sweetspot volumio[954]: info: camilladsp spawned new process with pid 2231, instance 2, run: true Oct 06 23:38:21 sweetspot volumio[954]: info: camilladsp service started and running in background, instance 2 Oct 06 23:38:21 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 23:38:21 sweetspot volumio[954]: xcb_connection_has_error() returned true Oct 06 23:38:21 sweetspot volumio[954]: cannot open device 'volumioHw': Device or resource busy Oct 06 23:38:21 sweetspot volumio[954]: error: FusionDsp - ----Hw detection failed :Error: Command failed: /data/plugins/audio_interface/fusiondsp/hw_params volumioHw >/data/configuration/audio_interface/fusiondsp/hwinfo.json Oct 06 23:38:21 sweetspot volumio[954]: xcb_connection_has_error() returned true Oct 06 23:38:21 sweetspot volumio[954]: cannot open device 'volumioHw': Device or resource busy Oct 06 23:38:21 sweetspot volumio[954]: info: FusionDsp loaded Oct 06 23:38:21 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 06 23:38:21 sweetspot sudo[2241]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Oct 06 23:38:21 sweetspot sudo[2241]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:21 sweetspot volumio[954]: info: FusionDsp - Reporting Fusion DSP Enabled Oct 06 23:38:21 sweetspot volumio[954]: info: Adding Signal Path Element [object Object] Oct 06 23:38:21 sweetspot volumio[954]: info: Adding fusiondspeq DSP Signal Path Element Oct 06 23:38:21 sweetspot volumio[954]: info: FusionDsp - ---- installed callbackRead Oct 06 23:38:21 sweetspot volumio[954]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 06 23:38:21 sweetspot volumio[954]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 06 23:38:21 sweetspot volumio[954]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 06 23:38:21 sweetspot volumio[954]: info: FusionDsp - Nulleq applied Oct 06 23:38:21 sweetspot volumio[954]: info: FusionDsp - Effects disabled Oct 06 23:38:21 sweetspot volumio[954]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Oct 06 23:38:21 sweetspot volumio[954]: info: FusionDsp - ---- read samplerate from file: 44100 Oct 06 23:38:21 sweetspot volumio[954]: info: camilladsp stopping service pid 2231... Oct 06 23:38:21 sweetspot volumio[954]: info: camilladsp service terminated, instance 2 Oct 06 23:38:21 sweetspot volumio[954]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 06 23:38:21 sweetspot volumio[954]: info: FusionDsp - Nulleq applied Oct 06 23:38:21 sweetspot volumio[954]: info: FusionDsp - Effects disabled Oct 06 23:38:21 sweetspot volumio[954]: info: camilladsp service started and running in background, instance 2 Oct 06 23:38:21 sweetspot volumio[954]: info: FusionDsp - If filter freq >samplerate/2 then disable it Oct 06 23:38:21 sweetspot volumio[954]: info: FusionDsp - Nulleq applied Oct 06 23:38:21 sweetspot volumio[954]: info: FusionDsp - Effects disabled Oct 06 23:38:21 sweetspot volumio[954]: error: FusionDsp - WebSocket error: [object Object] Oct 06 23:38:21 sweetspot volumio[954]: error: FusionDsp - WebSocket error: [object Object] Oct 06 23:38:21 sweetspot volumio[954]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 Oct 06 23:38:21 sweetspot volumio[954]: info: camilladsp spawned new process with pid 2246, instance 2, run: true Oct 06 23:38:21 sweetspot systemd[1]: Started FusionDsp Daemon. Oct 06 23:38:21 sweetspot sudo[2241]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:22 sweetspot volumio[954]: info: TidalConnect service stoped! Oct 06 23:38:22 sweetspot volumio[954]: info: TidalConnect service stoped! Oct 06 23:38:22 sweetspot volumio[954]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 06 23:38:22 sweetspot volumio[954]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 06 23:38:22 sweetspot sudo[2264]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 06 23:38:22 sweetspot sudo[2264]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:22 sweetspot systemd[1]: Started Volumio Tidal Connect Service. Oct 06 23:38:22 sweetspot sudo[2264]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:22 sweetspot volumio[954]: info: TidalConnect service stoped! Oct 06 23:38:22 sweetspot volumio[954]: info: Executing endpoint tc_getconfig Oct 06 23:38:22 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Oct 06 23:38:22 sweetspot vtcs[2266]: STARTING TidalConnect services, version: 1.4.0.34 Oct 06 23:38:22 sweetspot volumio[954]: info: TidalConnect service stoped! Oct 06 23:38:22 sweetspot vtcs[2266]: STARTED TidalConnect services. Oct 06 23:38:22 sweetspot volumio[954]: info: Executing endpoint tc_connect Oct 06 23:38:22 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Oct 06 23:38:22 sweetspot volumio[954]: info: Connecting to TidalConnect Oct 06 23:38:22 sweetspot volumio[954]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Oct 06 23:38:22 sweetspot volumio[954]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Oct 06 23:38:22 sweetspot volumio[954]: info: CoreCommandRouter::servicePushState Oct 06 23:38:22 sweetspot volumio[954]: info: CoreStateMachine::pushState Oct 06 23:38:22 sweetspot volumio[954]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 06 23:38:22 sweetspot volumio[954]: info: CoreCommandRouter::volumioPushState Oct 06 23:38:22 sweetspot volumio[954]: info: CorePlayQueue::getTrack 5 Oct 06 23:38:22 sweetspot volumio[954]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect Oct 06 23:38:22 sweetspot volumio[954]: info: CoreCommandRouter::servicePushState Oct 06 23:38:22 sweetspot volumio[954]: info: CoreStateMachine::pushState Oct 06 23:38:22 sweetspot volumio[954]: info: CoreCommandRouter::volumioPushState Oct 06 23:38:22 sweetspot volumio[954]: info: CorePlayQueue::getTrack 5 Oct 06 23:38:22 sweetspot volumio[954]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect Oct 06 23:38:22 sweetspot sudo[2296]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Oct 06 23:38:22 sweetspot sudo[2296]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 23:38:22 sweetspot sudo[2296]: pam_unix(sudo:session): session closed for user root Oct 06 23:38:25 sweetspot volumio[954]: info: Checking Spotify Web API Oct 06 23:38:25 sweetspot volumio[954]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 06 23:38:25 sweetspot volumio[954]: Error [ERR_SOCKET_DGRAM_NOT_RUNNING]: Not running Oct 06 23:38:25 sweetspot volumio[954]: at healthCheck (dgram.js:897:11) Oct 06 23:38:25 sweetspot volumio[954]: at Socket.send (dgram.js:622:3) Oct 06 23:38:25 sweetspot volumio[954]: at SpotConnEvents.sendmsg (/data/plugins/music_service/spop/SpotConnController.js:106:21) Oct 06 23:38:25 sweetspot volumio[954]: at ControllerSpotify.checkWebApi (/data/plugins/music_service/spop/index.js:2354:23) Oct 06 23:38:25 sweetspot volumio[954]: at Timeout._onTimeout (/data/plugins/music_service/spop/index.js:2694:18) Oct 06 23:38:25 sweetspot volumio[954]: at listOnTimeout (internal/timers.js:554:17) Oct 06 23:38:25 sweetspot volumio[954]: at processTimers (internal/timers.js:497:7) { Oct 06 23:38:25 sweetspot volumio[954]: code: 'ERR_SOCKET_DGRAM_NOT_RUNNING' Oct 06 23:38:25 sweetspot volumio[954]: } Oct 06 23:38:25 sweetspot volumio[954]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 06 23:38:25 sweetspot sudo[2312]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-06 23:37 Oct 06 23:38:25 sweetspot sudo[2312]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"