-- 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"