-- Logs begin at Thu 2019-02-14 18:11:58 HKT, end at Tue 2024-04-30 12:12:53 HKT. -- Apr 30 12:11:00 rivo volumio[5466]: info: TidalConnect service started! Apr 30 12:11:00 rivo volumio[5466]: info: TidalConnect service started! Apr 30 12:11:01 rivo volumio[5466]: info: TidalConnect service started! Apr 30 12:11:01 rivo volumio[5466]: info: TidalConnect service started! Apr 30 12:11:42 rivo kernel: usb 1-1.4.2: new high-speed USB device number 12 using xhci-hcd Apr 30 12:11:42 rivo kernel: usb 1-1.4.2: New USB device found, idVendor=27ac, idProduct=1070 Apr 30 12:11:42 rivo kernel: usb 1-1.4.2: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Apr 30 12:11:42 rivo kernel: usb 1-1.4.2: Product: LSX II LT Apr 30 12:11:42 rivo kernel: usb 1-1.4.2: Manufacturer: KEF Apr 30 12:11:42 rivo kernel: input: KEF LSX II LT as /devices/platform/ff500000.dwc3/xhci-hcd.0.auto/usb1/1-1/1-1.4/1-1.4.2/1-1.4.2:1.0/0003:27AC:1070.0008/input/input13 Apr 30 12:11:42 rivo kernel: hid-generic 0003:27AC:1070.0008: input,hidraw0: USB HID v1.00 Device [KEF LSX II LT] on usb-xhci-hcd.0.auto-1.4.2/input0 Apr 30 12:11:43 rivo systemd-udevd[12258]: Process '/usr/sbin/alsactl -E HOME=/run/alsa restore 5' failed with exit code 99. Apr 30 12:11:43 rivo volumio[5466]: info: Apr 30 12:11:43 rivo volumio[5466]: ---------------------------- USB Audio Device Attached Apr 30 12:11:43 rivo volumio[5466]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Apr 30 12:11:43 rivo systemd-udevd[12263]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Apr 30 12:11:52 rivo kernel: usb 1-1.4.2: USB disconnect, device number 12 Apr 30 12:11:52 rivo volumio[5466]: info: Apr 30 12:11:52 rivo volumio[5466]: ---------------------------- USB Audio Device Detached Apr 30 12:11:52 rivo volumio[5466]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach Apr 30 12:11:52 rivo volumio[5466]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Apr 30 12:11:52 rivo volumio[5466]: No protocol specified Apr 30 12:11:52 rivo volumio[5466]: xcb_connection_has_error() returned true Apr 30 12:12:49 rivo volumio[5466]: info: CorePlayQueue::getTrack 0 Apr 30 12:12:49 rivo volumio[5466]: info: CorePlayQueue::getTrack 1 Apr 30 12:12:49 rivo volumio[5466]: info: Prefetching next song Apr 30 12:12:49 rivo volumio[5466]: info: DOING PREFETCH IN MPD Apr 30 12:12:49 rivo volumio[5466]: verbose: ControllerMpd::sendMpdCommand add "NAS/contents/CD Library/Adele/30/02 Easy On Me.wav" Apr 30 12:12:49 rivo volumio[5466]: info: Apr 30 12:12:49 rivo volumio[5466]: ---------------------------- MPD announces system playlist update Apr 30 12:12:49 rivo volumio[5466]: info: Ignoring MPD Status Update Apr 30 12:12:49 rivo volumio[5466]: info: sendMpdCommand add "NAS/contents/CD Library/Adele/30/02 Easy On Me.wav" took 7 milliseconds Apr 30 12:12:49 rivo volumio[5466]: verbose: ControllerMpd::sendMpdCommand consume 1 Apr 30 12:12:49 rivo volumio[5466]: info: Apr 30 12:12:49 rivo volumio[5466]: ---------------------------- MPD announces system playlist update Apr 30 12:12:49 rivo volumio[5466]: info: Ignoring MPD Status Update Apr 30 12:12:49 rivo volumio[5466]: info: Apr 30 12:12:49 rivo volumio[5466]: ---------------------------- MPD announces state update: options Apr 30 12:12:49 rivo volumio[5466]: info: ------------------------------ 16ms Apr 30 12:12:49 rivo volumio[5466]: info: sendMpdCommand consume 1 took 11 milliseconds Apr 30 12:12:49 rivo volumio[5466]: info: ControllerMpd::getState Apr 30 12:12:49 rivo volumio[5466]: verbose: ControllerMpd::sendMpdCommand status Apr 30 12:12:49 rivo volumio[5466]: info: ------------------------------ 12ms Apr 30 12:12:49 rivo volumio[5466]: info: Apr 30 12:12:49 rivo volumio[5466]: ---------------------------- MPD announces state update: options Apr 30 12:12:49 rivo volumio[5466]: info: ControllerMpd::getState Apr 30 12:12:49 rivo volumio[5466]: verbose: ControllerMpd::sendMpdCommand status Apr 30 12:12:49 rivo volumio[5466]: info: sendMpdCommand status took 8 milliseconds Apr 30 12:12:49 rivo volumio[5466]: info: sendMpdCommand status took 2 milliseconds Apr 30 12:12:49 rivo volumio[5466]: verbose: ControllerMpd::parseState Apr 30 12:12:49 rivo volumio[5466]: verbose: ControllerMpd::parseState Apr 30 12:12:49 rivo volumio[5466]: info: ControllerMpd::pushState Apr 30 12:12:49 rivo volumio[5466]: info: CoreCommandRouter::servicePushState Apr 30 12:12:49 rivo volumio[5466]: info: CoreStateMachine::pushState Apr 30 12:12:49 rivo volumio[5466]: info: CorePlayQueue::getTrack 0 Apr 30 12:12:49 rivo volumio[5466]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 12:12:49 rivo volumio[5466]: info: CoreCommandRouter::volumioPushState Apr 30 12:12:49 rivo volumio[5466]: info: MRS: Pushing multiroomSync output update for this device Apr 30 12:12:49 rivo volumio[5466]: info: MRS: Pushing multiroomSync output Apr 30 12:12:49 rivo volumio[5466]: info: CorePlayQueue::getTrack 0 Apr 30 12:12:49 rivo volumio[5466]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 30 12:12:49 rivo volumio[5466]: verbose: CURRENT POSITION 0 Apr 30 12:12:49 rivo volumio[5466]: info: CoreStateMachine::syncState stateService stop Apr 30 12:12:49 rivo volumio[5466]: info: CoreStateMachine::syncState currentStatus play Apr 30 12:12:49 rivo volumio[5466]: info: CoreStateMachine::pushState Apr 30 12:12:49 rivo volumio[5466]: info: CorePlayQueue::getTrack 1 Apr 30 12:12:49 rivo volumio[5466]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 30 12:12:49 rivo volumio[5466]: info: CoreCommandRouter::volumioPushState Apr 30 12:12:49 rivo volumio[5466]: info: MRS: Pushing multiroomSync output update for this device Apr 30 12:12:49 rivo volumio[5466]: info: MRS: Pushing multiroomSync output Apr 30 12:12:49 rivo volumio[5466]: info: CoreStateMachine::pushState Apr 30 12:12:49 rivo volumio[5466]: info: CorePlayQueue::getTrack 1 Apr 30 12:12:49 rivo volumio[5466]: info: CoreCommandRouter::volumioPushState Apr 30 12:12:49 rivo volumio[5466]: info: MRS: Pushing multiroomSync output update for this device Apr 30 12:12:49 rivo volumio[5466]: info: MRS: Pushing multiroomSync output Apr 30 12:12:49 rivo volumio[5466]: info: ControllerMpd::pushState Apr 30 12:12:49 rivo volumio[5466]: info: CoreCommandRouter::servicePushState Apr 30 12:12:49 rivo volumio[5466]: info: CoreStateMachine::pushState Apr 30 12:12:49 rivo volumio[5466]: info: CorePlayQueue::getTrack 1 Apr 30 12:12:49 rivo volumio[5466]: info: CoreCommandRouter::volumioPushState Apr 30 12:12:49 rivo volumio[5466]: info: MRS: Pushing multiroomSync output update for this device Apr 30 12:12:49 rivo volumio[5466]: info: MRS: Pushing multiroomSync output Apr 30 12:12:49 rivo volumio[5466]: info: CorePlayQueue::getTrack 1 Apr 30 12:12:49 rivo volumio[5466]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Apr 30 12:12:49 rivo volumio[5466]: verbose: CURRENT POSITION 1 Apr 30 12:12:49 rivo volumio[5466]: info: CoreStateMachine::syncState stateService stop Apr 30 12:12:49 rivo volumio[5466]: info: CoreStateMachine::syncState currentStatus stop Apr 30 12:12:49 rivo volumio[5466]: info: CoreStateMachine::pushState Apr 30 12:12:49 rivo volumio[5466]: info: CorePlayQueue::getTrack 1 Apr 30 12:12:49 rivo volumio[5466]: info: CoreCommandRouter::volumioPushState Apr 30 12:12:49 rivo volumio[5466]: info: MRS: Pushing multiroomSync output update for this device Apr 30 12:12:49 rivo volumio[5466]: info: MRS: Pushing multiroomSync output Apr 30 12:12:49 rivo volumio[5466]: info: No code Apr 30 12:12:49 rivo volumio[5466]: info: CoreStateMachine::pushState Apr 30 12:12:49 rivo volumio[5466]: info: CorePlayQueue::getTrack 1 Apr 30 12:12:49 rivo volumio[5466]: info: CoreCommandRouter::volumioPushState Apr 30 12:12:49 rivo volumio[5466]: info: MRS: Pushing multiroomSync output update for this device Apr 30 12:12:49 rivo volumio[5466]: info: MRS: Pushing multiroomSync output Apr 30 12:12:49 rivo volumio[5466]: info: ------------------------------ 179ms Apr 30 12:12:49 rivo volumio[5466]: info: ------------------------------ 172ms Apr 30 12:12:49 rivo volumio[5466]: info: Signalling Playback active due to playback status change Apr 30 12:12:49 rivo volumio[5466]: info: Updating RAAT Signal Path Apr 30 12:12:49 rivo volumio[5466]: info: Updating RAAT Signal Path Apr 30 12:12:49 rivo volumio[5466]: info: Updating RAAT Signal Path Apr 30 12:12:49 rivo volumio[5466]: info: Updating RAAT Signal Path Apr 30 12:12:49 rivo volumio[5466]: info: Updating RAAT Signal Path Apr 30 12:12:49 rivo volumio[5466]: info: Updating RAAT Signal Path Apr 30 12:12:49 rivo volumio[5466]: info: MCU Signalled Playback Inactive Apr 30 12:12:52 rivo volumio[5466]: info: MRS: STARTING volumioStreaming Apr 30 12:12:52 rivo volumio[5466]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 30 12:12:52 rivo volumio[5466]: TypeError: Cannot read property 'mediaSessionId' of null Apr 30 12:12:52 rivo volumio[5466]: at fn.MediaController.sessionRequest (/volumio/app/plugins/audio_interface/multiroom/node_modules/castv2-client/lib/controllers/media.js:88:45) Apr 30 12:12:52 rivo volumio[5466]: at fn.MediaController.stop (/volumio/app/plugins/audio_interface/multiroom/node_modules/castv2-client/lib/controllers/media.js:107:8) Apr 30 12:12:52 rivo volumio[5466]: at DefaultMediaReceiver.stop (/volumio/app/plugins/audio_interface/multiroom/node_modules/castv2-client/lib/senders/default-media-receiver.js:42:19) Apr 30 12:12:52 rivo volumio[5466]: at Timeout._onTimeout (/volumio/app/plugins/audio_interface/multiroom/multiroom_real:1:5002) Apr 30 12:12:52 rivo volumio[5466]: at listOnTimeout (internal/timers.js:557:17) Apr 30 12:12:52 rivo volumio[5466]: at processTimers (internal/timers.js:500:7) Apr 30 12:12:52 rivo volumio[5466]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 30 12:12:52 rivo sudo[12491]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/stream.m3u8 /tmp/hls/stream0.ts /tmp/hls/stream1.ts /tmp/hls/stream10.ts /tmp/hls/stream11.ts /tmp/hls/stream12.ts /tmp/hls/stream13.ts /tmp/hls/stream14.ts /tmp/hls/stream15.ts /tmp/hls/stream16.ts /tmp/hls/stream17.ts /tmp/hls/stream18.ts /tmp/hls/stream19.ts /tmp/hls/stream2.ts /tmp/hls/stream20.ts /tmp/hls/stream21.ts /tmp/hls/stream22.ts /tmp/hls/stream23.ts /tmp/hls/stream24.ts /tmp/hls/stream25.ts /tmp/hls/stream26.ts /tmp/hls/stream27.ts /tmp/hls/stream28.ts /tmp/hls/stream29.ts /tmp/hls/stream3.ts /tmp/hls/stream30.ts /tmp/hls/stream31.ts /tmp/hls/stream32.ts /tmp/hls/stream33.ts /tmp/hls/stream34.ts /tmp/hls/stream35.ts /tmp/hls/stream36.ts /tmp/hls/stream37.ts /tmp/hls/stream38.ts /tmp/hls/stream39.ts /tmp/hls/stream4.ts /tmp/hls/stream40.ts /tmp/hls/stream41.ts /tmp/hls/stream42.ts /tmp/hls/stream43.ts /tmp/hls/stream44.ts /tmp/hls/stream45.ts Apr 30 12:12:52 rivo sudo[12491]: volumio : (command continued) /tmp/hls/stream46.ts /tmp/hls/stream47.ts /tmp/hls/stream48.ts /tmp/hls/stream49.ts /tmp/hls/stream5.ts /tmp/hls/stream50.ts /tmp/hls/stream51.ts /tmp/hls/stream52.ts /tmp/hls/stream53.ts /tmp/hls/stream54.ts /tmp/hls/stream55.ts /tmp/hls/stream56.ts /tmp/hls/stream57.ts /tmp/hls/stream58.ts /tmp/hls/stream59.ts /tmp/hls/stream6.ts /tmp/hls/stream60.ts /tmp/hls/stream61.ts /tmp/hls/stream62.ts /tmp/hls/stream7.ts /tmp/hls/stream8.ts /tmp/hls/stream9.ts Apr 30 12:12:52 rivo sudo[12491]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 12:12:52 rivo sudo[12491]: pam_unix(sudo:session): session closed for user root Apr 30 12:12:52 rivo sudo[12493]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumioStreaming Apr 30 12:12:52 rivo sudo[12493]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 12:12:52 rivo systemd[1]: Stopping VolumioStreamingService... Apr 30 12:12:52 rivo systemd[1]: volumioStreaming.service: Main process exited, code=killed, status=15/TERM Apr 30 12:12:52 rivo systemd[1]: volumioStreaming.service: Succeeded. Apr 30 12:12:52 rivo systemd[1]: Stopped VolumioStreamingService. Apr 30 12:12:52 rivo systemd[1]: Started VolumioStreamingService. Apr 30 12:12:52 rivo sudo[12493]: pam_unix(sudo:session): session closed for user root Apr 30 12:12:52 rivo sudo[12524]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm -f /tmp/hls/* Apr 30 12:12:52 rivo sudo[12524]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 12:12:52 rivo sudo[12524]: pam_unix(sudo:session): session closed for user root Apr 30 12:12:53 rivo sudo[12558]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-30 12:11 Apr 30 12:12:53 rivo sudo[12558]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="e831866afe2db61aee9333a8f5ba9d9fd36609c7" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivo" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sun 18 Feb 2024 11:41:55 AM CET" VOLUMIO_VERSION="3.629" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo" VOLUMIO_HASH="b0437c7088d6645a661a49f6d9fa596a"