-- Logs begin at Mon 2024-07-01 23:57:37 BST, end at Sat 2024-07-20 08:26:23 BST. -- Jul 20 08:25:03 rivo volumio[3376]: info: CorePlayQueue::getTrack 0 Jul 20 08:25:03 rivo volumio[3376]: info: CorePlayQueue::getTrack 1 Jul 20 08:25:03 rivo volumio[3376]: info: Prefetching next song Jul 20 08:25:03 rivo volumio[3376]: info: [1721460303189] ControllerTidal::prefetch Jul 20 08:25:03 rivo volumio[3376]: info: Getting stream with soundQuality LOSSLESS Jul 20 08:25:03 rivo volumio[3376]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/73603377&soundQuality=LOSSLESS" Jul 20 08:25:03 rivo volumio[3376]: info: Jul 20 08:25:03 rivo volumio[3376]: ---------------------------- MPD announces system playlist update Jul 20 08:25:03 rivo volumio[3376]: info: Ignoring MPD Status Update Jul 20 08:25:03 rivo volumio[3376]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/73603377&soundQuality=LOSSLESS" took 2 milliseconds Jul 20 08:25:03 rivo volumio[3376]: info: CoreStateMachine::setConsumeUpdateService mpd Jul 20 08:25:03 rivo volumio[3376]: verbose: ControllerMpd::sendMpdCommand consume 1 Jul 20 08:25:03 rivo volumio[3376]: info: ------------------------------ 4ms Jul 20 08:25:03 rivo volumio[3376]: info: sendMpdCommand consume 1 took 2 milliseconds Jul 20 08:25:05 rivo volumio[3376]: STREAMING PROXY: Handling url /?data=tidal://song/73603377&soundQuality=LOSSLESS Jul 20 08:25:05 rivo volumio[3376]: info: Executing endpoint getStreamUrltidal Jul 20 08:25:05 rivo volumio[3376]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Jul 20 08:25:05 rivo volumio[3376]: info: getStreamUrl took 494 milliseconds Jul 20 08:25:05 rivo volumio[3376]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKwgDEic0YmQ3MWJmYzU3MDVlNGVhYzg4MmNkNDVmYTE4YTFjOV82MS5tcDQ/0.flac?Expires=1721463905&Signature=JcUtzK6Ergd2lLwUINVW4b1oxUAb2zu0PASM0fHQQZtXohryb1KpjUUmLSfbau~tjSvDbpV7vpsrudTIzrsuelFGBkgfbZRsFPWKAr9lKRiKq5iO1krxNUTxNp0Y~yJmlGBYb40yhH4HjmQ9Xu99kTIwkIaSIC2HVvdN30M2Q0ZrbstSk6L8uZaJn1fCPvois5wJT-n0MjSEUcUKJPmwIrm5KbORsdNxSH7Q7nhO51MDhMI4Ek4YPnFV0KRtxGNvTMOXgJuOuVcYkGFf4UXUPpwlGgECltKZnJ8eRcp58bnVEWaWcGp0GTOXYDUmFY2D1d9z3-QhzHsneKKM0kH4TA__&Key-Pair-Id=K14LZCZ9QUI4JL Jul 20 08:25:06 rivo volumio[3376]: STREAMING PROXY: Response: 200, length: 27832509 Jul 20 08:25:07 rivo volumio[3376]: STREAMING PROXY: Client dropped request, destroying Jul 20 08:25:07 rivo volumio[3376]: info: CoreStateMachine::startPlaybackTimer Jul 20 08:25:07 rivo volumio[3376]: info: CorePlayQueue::getTrack 1 Jul 20 08:25:07 rivo volumio[3376]: info: Jul 20 08:25:07 rivo volumio[3376]: ---------------------------- MPD announces system playlist update Jul 20 08:25:07 rivo volumio[3376]: info: Ignoring MPD Status Update Jul 20 08:25:07 rivo volumio[3376]: info: Jul 20 08:25:07 rivo volumio[3376]: ---------------------------- MPD announces state update: player Jul 20 08:25:07 rivo volumio[3376]: info: ControllerMpd::getState Jul 20 08:25:07 rivo volumio[3376]: verbose: ControllerMpd::sendMpdCommand status Jul 20 08:25:07 rivo volumio[3376]: info: ------------------------------ 10ms Jul 20 08:25:07 rivo volumio[3376]: info: sendMpdCommand status took 8 milliseconds Jul 20 08:25:07 rivo volumio[3376]: verbose: ControllerMpd::parseState Jul 20 08:25:07 rivo volumio[3376]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jul 20 08:25:07 rivo volumio[3376]: info: sendMpdCommand playlistinfo took 2 milliseconds Jul 20 08:25:07 rivo volumio[3376]: verbose: ControllerMpd::parseTrackInfo Jul 20 08:25:07 rivo volumio[3376]: info: ControllerMpd::pushState Jul 20 08:25:07 rivo volumio[3376]: info: CoreCommandRouter::servicePushState Jul 20 08:25:07 rivo volumio[3376]: info: CorePlayQueue::getTrack 1 Jul 20 08:25:07 rivo volumio[3376]: verbose: STATE SERVICE {"status":"play","position":0,"seek":22,"duration":236,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"799 Kbps","isStreaming":false,"title":"73603377&soundQuality=LOSSLESS","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/73603377&soundQuality=LOSSLESS","trackType":"tidal"} Jul 20 08:25:07 rivo volumio[3376]: verbose: CURRENT POSITION 1 Jul 20 08:25:07 rivo volumio[3376]: info: CoreStateMachine::syncState stateService play Jul 20 08:25:07 rivo volumio[3376]: info: CoreStateMachine::syncState currentStatus play Jul 20 08:25:07 rivo volumio[3376]: info: Received an update from plugin. extracting info from payload Jul 20 08:25:07 rivo volumio[3376]: info: CoreStateMachine::pushState Jul 20 08:25:07 rivo volumio[3376]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 20 08:25:07 rivo volumio[3376]: info: CoreCommandRouter::volumioPushState Jul 20 08:25:07 rivo volumio[3376]: info: MRS: Pushing multiroomSync output update for this device Jul 20 08:25:07 rivo volumio[3376]: info: MRS: Pushing multiroomSync output Jul 20 08:25:07 rivo volumio[3376]: info: CoreStateMachine::pushState Jul 20 08:25:07 rivo volumio[3376]: info: CoreCommandRouter::volumioPushState Jul 20 08:25:07 rivo volumio[3376]: info: MRS: Pushing multiroomSync output update for this device Jul 20 08:25:07 rivo volumio[3376]: info: MRS: Pushing multiroomSync output Jul 20 08:25:07 rivo volumio[3376]: info: ------------------------------ 42ms Jul 20 08:25:07 rivo volumio[3376]: info: [LastFM] Current track has sufficient metadata: title (A House Is Not a Motel) and artist (Arthur Lee) passed on explicitly Jul 20 08:25:07 rivo volumio[3376]: error: [LastFM] plugin is not authenticated, please retry, or track info could not be determined (very rare) Jul 20 08:25:07 rivo volumio[3376]: info: Signalling Playback active due to playback status change Jul 20 08:25:07 rivo volumio[3376]: info: Updating RAAT Signal Path Jul 20 08:25:07 rivo volumio[3376]: info: Updating RAAT Signal Path Jul 20 08:25:07 rivo volumio[3376]: info: Signalling Playback active due to playback status change Jul 20 08:25:07 rivo volumio[3376]: info: Updating RAAT Signal Path Jul 20 08:25:07 rivo volumio[3376]: info: Updating RAAT Signal Path Jul 20 08:25:08 rivo volumio[3376]: info: CoreStateMachine::pushState Jul 20 08:25:08 rivo volumio[3376]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 20 08:25:08 rivo volumio[3376]: info: CoreCommandRouter::volumioPushState Jul 20 08:25:08 rivo volumio[3376]: info: MRS: Pushing multiroomSync output update for this device Jul 20 08:25:08 rivo volumio[3376]: info: MRS: Pushing multiroomSync output Jul 20 08:25:08 rivo volumio[3376]: info: Signalling Playback active due to playback status change Jul 20 08:25:08 rivo volumio[3376]: info: Updating RAAT Signal Path Jul 20 08:25:08 rivo volumio[3376]: info: Updating RAAT Signal Path Jul 20 08:25:50 rivo ntpd[16913]: 185.103.117.60 local addr 192.168.1.68 -> Jul 20 08:25:51 rivo ntpd[16913]: 176.58.127.165 local addr 192.168.1.68 -> Jul 20 08:25:54 rivo ntpd[16913]: 185.103.119.60 local addr 192.168.1.68 -> Jul 20 08:25:57 rivo ntpd[16913]: 82.219.4.30 local addr 192.168.1.68 -> Jul 20 08:25:59 rivo ntpd[16913]: 185.53.45.5 local addr 192.168.1.68 -> Jul 20 08:26:03 rivo ntpd[16913]: 193.150.34.2 local addr 192.168.1.68 -> Jul 20 08:26:06 rivo volumio[3376]: info: CoreCommandRouter::executeOnPlugin: multiroom , enableAudioOutput Jul 20 08:26:06 rivo volumio[3376]: info: MRS: Starting cast device: BRAVIA-4K-GB-39484909ed08a88d91e7dfd6beda00a6 Jul 20 08:26:06 rivo volumio[3376]: info: Enabled audio output: BRAVIA-4K-GB-39484909ed08a88d91e7dfd6beda00a6 Jul 20 08:26:06 rivo volumio[3376]: info: MRS: Setting this device as Streaming Server Jul 20 08:26:06 rivo volumio[3376]: info: Jul 20 08:26:06 rivo volumio[3376]: [1721460366129] ---------------------------- MRS: Setting Streaming Server Jul 20 08:26:06 rivo volumio[3376]: info: MRS: enable multiroom server output Jul 20 08:26:06 rivo volumio[3376]: info: MRS: Set multiroom target PCM to volumioMultiRoom Jul 20 08:26:06 rivo volumio[3376]: info: Changed audio target for /tmp/multiroom/server/switch.target to volumioMultiRoom Jul 20 08:26:06 rivo kernel: asoc-aml-card auge_sound: S/PDIF Playback disable Jul 20 08:26:06 rivo kernel: spdif_a keep clk continuous Jul 20 08:26:06 rivo kernel: aml_spdif_close Jul 20 08:26:06 rivo kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:spdif@0 Jul 20 08:26:06 rivo volumio[3376]: info: MRS: Set multiroom target PCM to volumioLocalPlayback Jul 20 08:26:06 rivo volumio[3376]: info: MRS: Connected to cast device: BRAVIA-4K-GB-39484909ed08a88d91e7dfd6beda00a6 Jul 20 08:26:06 rivo volumio[3376]: info: Changed audio target for /tmp/multiroom/client/switch.target to volumioLocalPlayback Jul 20 08:26:06 rivo volumio[3376]: info: MRS: STARTING volumioStreaming Jul 20 08:26:06 rivo sudo[18727]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Jul 20 08:26:06 rivo sudo[18727]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 20 08:26:06 rivo sudo[18727]: pam_unix(sudo:session): session closed for user root Jul 20 08:26:06 rivo sudo[18729]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumioStreaming Jul 20 08:26:06 rivo sudo[18729]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 20 08:26:06 rivo systemd[1]: Started VolumioStreamingService. Jul 20 08:26:06 rivo sudo[18729]: pam_unix(sudo:session): session closed for user root Jul 20 08:26:06 rivo volumio[3376]: info: MRS: volumioStreaming STARTED Jul 20 08:26:06 rivo sudo[18736]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Jul 20 08:26:06 rivo sudo[18736]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 20 08:26:06 rivo sudo[18736]: pam_unix(sudo:session): session closed for user root Jul 20 08:26:06 rivo volumio[3376]: info: CoreCommandRouter::executeOnPlugin: multiroom , enableAudioOutput Jul 20 08:26:06 rivo volumio[3376]: info: MRS: Stopping cast device: BRAVIA-4K-GB-39484909ed08a88d91e7dfd6beda00a6 Jul 20 08:26:07 rivo volumio[3376]: info: MRS: Starting cast device: BRAVIA-4K-GB-39484909ed08a88d91e7dfd6beda00a6 Jul 20 08:26:07 rivo volumio[3376]: info: Enabled audio output: BRAVIA-4K-GB-39484909ed08a88d91e7dfd6beda00a6 Jul 20 08:26:07 rivo volumio[3376]: info: MRS: Setting this device as Streaming Server Jul 20 08:26:07 rivo volumio[3376]: info: Jul 20 08:26:07 rivo volumio[3376]: [1721460367003] ---------------------------- MRS: Setting Streaming Server Jul 20 08:26:07 rivo volumio[3376]: info: MRS: enable multiroom server output Jul 20 08:26:07 rivo volumio[3376]: info: MRS: Set multiroom target PCM to volumioMultiRoom Jul 20 08:26:07 rivo volumio[3376]: info: Changed audio target for /tmp/multiroom/server/switch.target to volumioMultiRoom Jul 20 08:26:07 rivo volumio[3376]: info: MRS: Set multiroom target PCM to volumioLocalPlayback Jul 20 08:26:07 rivo volumio[3376]: info: Changed audio target for /tmp/multiroom/client/switch.target to volumioLocalPlayback Jul 20 08:26:07 rivo volumio[3376]: info: MRS: STARTING volumioStreaming Jul 20 08:26:07 rivo sudo[18752]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Jul 20 08:26:07 rivo sudo[18752]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 20 08:26:07 rivo sudo[18752]: pam_unix(sudo:session): session closed for user root Jul 20 08:26:07 rivo sudo[18755]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumioStreaming Jul 20 08:26:07 rivo sudo[18755]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 20 08:26:07 rivo volumio[3376]: info: MRS: Connected to cast device: BRAVIA-4K-GB-39484909ed08a88d91e7dfd6beda00a6 Jul 20 08:26:07 rivo systemd[1]: Stopping VolumioStreamingService... Jul 20 08:26:07 rivo systemd[1]: volumioStreaming.service: Main process exited, code=killed, status=15/TERM Jul 20 08:26:07 rivo volumio[3376]: ------------------------------------ BT MESSAGE: BT STATUS: running Jul 20 08:26:07 rivo systemd[1]: volumioStreaming.service: Succeeded. Jul 20 08:26:07 rivo systemd[1]: Stopped VolumioStreamingService. Jul 20 08:26:07 rivo volumio[3376]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Jul 20 08:26:07 rivo systemd[1]: Started VolumioStreamingService. Jul 20 08:26:07 rivo sudo[18755]: pam_unix(sudo:session): session closed for user root Jul 20 08:26:07 rivo volumio[3376]: info: MRS: volumioStreaming STARTED Jul 20 08:26:07 rivo sudo[18758]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Jul 20 08:26:07 rivo sudo[18758]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 20 08:26:07 rivo sudo[18758]: pam_unix(sudo:session): session closed for user root Jul 20 08:26:22 rivo volumio[3376]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Jul 20 08:26:22 rivo volumio[3376]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Jul 20 08:26:22 rivo volumio[3376]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 20 08:26:22 rivo volumio[3376]: TypeError: Cannot read property 'then' of undefined Jul 20 08:26:22 rivo volumio[3376]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Jul 20 08:26:22 rivo volumio[3376]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2260:30) Jul 20 08:26:22 rivo volumio[3376]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1435:26) Jul 20 08:26:22 rivo volumio[3376]: at Socket.emit (events.js:400:28) Jul 20 08:26:22 rivo volumio[3376]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jul 20 08:26:22 rivo volumio[3376]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Jul 20 08:26:22 rivo volumio[3376]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 20 08:26:23 rivo sudo[18814]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-07-20 08:25 Jul 20 08:26:23 rivo sudo[18814]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="4b122b2365bb8c09786cd63b50d1ea6db780eb4e" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="49f98390f2d84c6549f33dc85b694fbd99e4c720" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 04 Jun 2024 09:27:25 PM CEST" VOLUMIO_VERSION="3.703" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="891b8adfc94c7cc44424972b60e8e09c"