-- Logs begin at Fri 2026-02-06 18:36:42 CET, end at Fri 2026-02-06 18:43:55 CET. -- Feb 06 18:42:20 rivoplus go-librespot[3903]: time="2026-02-06T18:42:20+01:00" level=trace msg="sent dealer ping" Feb 06 18:42:20 rivoplus go-librespot[3903]: time="2026-02-06T18:42:20+01:00" level=trace msg="received dealer pong" Feb 06 18:42:35 rivoplus volumio[3111]: info: CoreCommandRouter::servicePushState Feb 06 18:42:35 rivoplus volumio[3111]: info: CoreStateMachine::pushState Feb 06 18:42:35 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 06 18:42:35 rivoplus volumio[3111]: info: CoreCommandRouter::volumioPushState Feb 06 18:42:35 rivoplus volumio[3111]: info: CoreCommandRouter::volumioGetState Feb 06 18:42:35 rivoplus volumio[3111]: info: MRS: Pushing multiroomSync output update for this device Feb 06 18:42:35 rivoplus volumio[3111]: info: MRS: Pushing multiroomSync output Feb 06 18:42:35 rivoplus vtcs[3989]: [pause:147] Entering Feb 06 18:42:35 rivoplus vtcs[3989]: [feedThread:276] Exiting Feb 06 18:42:35 rivoplus vtcs[3989]: [pause:161] Exiting Feb 06 18:42:35 rivoplus volumio[3111]: info: Updating RAAT Signal Path Feb 06 18:42:35 rivoplus volumio[3111]: info: MCU Signalled Playback Inactive Feb 06 18:42:36 rivoplus vtcs[3989]: [start:106] Entering Feb 06 18:42:36 rivoplus vtcs[3989]: [start:113] Reopening PCM device... Feb 06 18:42:36 rivoplus volumio[3111]: info: CoreCommandRouter::servicePushState Feb 06 18:42:36 rivoplus volumio[3111]: info: CoreStateMachine::pushState Feb 06 18:42:36 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 06 18:42:36 rivoplus volumio[3111]: info: CoreCommandRouter::volumioPushState Feb 06 18:42:36 rivoplus volumio[3111]: info: CoreCommandRouter::volumioGetState Feb 06 18:42:36 rivoplus volumio[3111]: info: MRS: Pushing multiroomSync output update for this device Feb 06 18:42:36 rivoplus volumio[3111]: info: MRS: Pushing multiroomSync output Feb 06 18:42:36 rivoplus volumio[3111]: info: Signalling Playback active due to playback status change Feb 06 18:42:36 rivoplus vtcs[3989]: [start:115] PCM opened successfully. Feb 06 18:42:36 rivoplus vtcs[3989]: [start:120] Exiting Feb 06 18:42:36 rivoplus vtcs[3989]: [feedThread:223] Entering Feb 06 18:42:36 rivoplus volumio[3111]: info: Updating RAAT Signal Path Feb 06 18:42:36 rivoplus volumio[3111]: info: MCU Signalled Playback Active Feb 06 18:42:36 rivoplus volumio[3111]: info: CoreCommandRouter::servicePushState Feb 06 18:42:36 rivoplus volumio[3111]: info: CoreStateMachine::pushState Feb 06 18:42:36 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 06 18:42:36 rivoplus volumio[3111]: info: CoreCommandRouter::volumioPushState Feb 06 18:42:36 rivoplus volumio[3111]: info: CoreCommandRouter::volumioGetState Feb 06 18:42:36 rivoplus volumio[3111]: info: MRS: Pushing multiroomSync output update for this device Feb 06 18:42:36 rivoplus volumio[3111]: info: MRS: Pushing multiroomSync output Feb 06 18:42:36 rivoplus volumio[3111]: info: Signalling Playback active due to playback status change Feb 06 18:42:36 rivoplus volumio[3111]: info: Updating RAAT Signal Path Feb 06 18:42:40 rivoplus vtcs[3989]: [pause:147] Entering Feb 06 18:42:40 rivoplus volumio[3111]: info: CoreCommandRouter::servicePushState Feb 06 18:42:40 rivoplus volumio[3111]: info: CoreStateMachine::pushState Feb 06 18:42:40 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 06 18:42:40 rivoplus volumio[3111]: info: CoreCommandRouter::volumioPushState Feb 06 18:42:40 rivoplus volumio[3111]: info: CoreCommandRouter::volumioGetState Feb 06 18:42:40 rivoplus volumio[3111]: info: MRS: Pushing multiroomSync output update for this device Feb 06 18:42:40 rivoplus vtcs[3989]: [feedThread:276] Exiting Feb 06 18:42:40 rivoplus volumio[3111]: info: MRS: Pushing multiroomSync output Feb 06 18:42:40 rivoplus vtcs[3989]: [pause:161] Exiting Feb 06 18:42:40 rivoplus volumio[3111]: info: Updating RAAT Signal Path Feb 06 18:42:40 rivoplus volumio[3111]: info: MCU Signalled Playback Inactive Feb 06 18:42:45 rivoplus go-librespot[3903]: time="2026-02-06T18:42:45+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Feb 06 18:42:45 rivoplus go-librespot[3903]: time="2026-02-06T18:42:45+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DX4JAvHpjipBk" Feb 06 18:42:49 rivoplus go-librespot[3903]: time="2026-02-06T18:42:49+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Feb 06 18:42:49 rivoplus go-librespot[3903]: time="2026-02-06T18:42:49+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1E8Ky9PYWJr9wv" Feb 06 18:42:49 rivoplus go-librespot[3903]: time="2026-02-06T18:42:49+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Feb 06 18:42:49 rivoplus go-librespot[3903]: time="2026-02-06T18:42:49+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1E8IyyyS3wl9s6" Feb 06 18:42:49 rivoplus go-librespot[3903]: time="2026-02-06T18:42:49+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Feb 06 18:42:49 rivoplus go-librespot[3903]: time="2026-02-06T18:42:49+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DXbjYER0JjzBA" Feb 06 18:42:49 rivoplus go-librespot[3903]: time="2026-02-06T18:42:49+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Feb 06 18:42:49 rivoplus go-librespot[3903]: time="2026-02-06T18:42:49+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1E4nxtJ6Wjch6f" Feb 06 18:42:50 rivoplus go-librespot[3903]: time="2026-02-06T18:42:50+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Feb 06 18:42:50 rivoplus go-librespot[3903]: time="2026-02-06T18:42:50+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1E36lenx2cm5vr" Feb 06 18:42:50 rivoplus go-librespot[3903]: time="2026-02-06T18:42:50+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1E37DCaAvpQrDX" Feb 06 18:42:50 rivoplus go-librespot[3903]: time="2026-02-06T18:42:50+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Feb 06 18:42:50 rivoplus go-librespot[3903]: time="2026-02-06T18:42:50+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1E8IyyyS3wl9s6" Feb 06 18:42:50 rivoplus go-librespot[3903]: time="2026-02-06T18:42:50+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Feb 06 18:42:50 rivoplus go-librespot[3903]: time="2026-02-06T18:42:50+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1E39Lv0h6qCnbQ" Feb 06 18:42:50 rivoplus go-librespot[3903]: time="2026-02-06T18:42:50+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Feb 06 18:42:50 rivoplus go-librespot[3903]: time="2026-02-06T18:42:50+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1EQntZpEGgfBif" Feb 06 18:42:50 rivoplus go-librespot[3903]: time="2026-02-06T18:42:50+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Feb 06 18:42:50 rivoplus go-librespot[3903]: time="2026-02-06T18:42:50+01:00" level=trace msg="sent dealer ping" Feb 06 18:42:50 rivoplus go-librespot[3903]: time="2026-02-06T18:42:50+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DWWiDhnQ2IIru" Feb 06 18:42:50 rivoplus go-librespot[3903]: time="2026-02-06T18:42:50+01:00" level=trace msg="received dealer pong" Feb 06 18:42:51 rivoplus go-librespot[3903]: time="2026-02-06T18:42:51+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Feb 06 18:42:51 rivoplus go-librespot[3903]: time="2026-02-06T18:42:51+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DWVlLVXKTOAYa" Feb 06 18:42:51 rivoplus go-librespot[3903]: time="2026-02-06T18:42:51+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DWWuIAAkPM0Lu" Feb 06 18:42:51 rivoplus go-librespot[3903]: time="2026-02-06T18:42:51+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Feb 06 18:42:51 rivoplus go-librespot[3903]: time="2026-02-06T18:42:51+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 137" Feb 06 18:42:51 rivoplus go-librespot[3903]: time="2026-02-06T18:42:51+01:00" level=debug msg="skipping dealer message" uri="hm://playlist/v2/playlist/37i9dQZF1DXdxcBWuJkbcy" Feb 06 18:42:54 rivoplus go-librespot[3903]: time="2026-02-06T18:42:54+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 370" Feb 06 18:42:54 rivoplus go-librespot[3903]: time="2026-02-06T18:42:54+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Feb 06 18:42:54 rivoplus go-librespot[3903]: time="2026-02-06T18:42:54+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1363" Feb 06 18:42:54 rivoplus go-librespot[3903]: time="2026-02-06T18:42:54+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 06 18:42:54 rivoplus go-librespot[3903]: time="2026-02-06T18:42:54+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1111" Feb 06 18:42:54 rivoplus go-librespot[3903]: time="2026-02-06T18:42:54+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 06 18:42:55 rivoplus go-librespot[3903]: time="2026-02-06T18:42:55+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1199" Feb 06 18:42:55 rivoplus go-librespot[3903]: time="2026-02-06T18:42:55+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 458" Feb 06 18:42:55 rivoplus go-librespot[3903]: time="2026-02-06T18:42:55+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 06 18:42:55 rivoplus go-librespot[3903]: time="2026-02-06T18:42:55+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Feb 06 18:42:57 rivoplus go-librespot[3903]: time="2026-02-06T18:42:57+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Feb 06 18:42:57 rivoplus go-librespot[3903]: time="2026-02-06T18:42:57+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1146" Feb 06 18:42:57 rivoplus go-librespot[3903]: time="2026-02-06T18:42:57+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Feb 06 18:42:57 rivoplus go-librespot[3903]: time="2026-02-06T18:42:57+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 06 18:43:09 rivoplus go-librespot[3903]: time="2026-02-06T18:43:09+01:00" level=debug msg="handling transfer player command from 8dad67db998019741bc18dc7c1d726e957a3f616" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=debug msg="resolved context of track" uri="spotify:playlist:37i9dQZF1E8IyyyS3wl9s6" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=trace msg="fetched new page 0 with 50 items (list: 50)" uri="spotify:playlist:37i9dQZF1E8IyyyS3wl9s6" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=debug msg="loading track (paused: false, position: 16846ms)" uri="spotify:track:25mjZuMkkML0LYJXfsXyi2" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=trace msg="emitting websocket event: will_play" Feb 06 18:43:10 rivoplus volumio[3111]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:37i9dQZF1E8IyyyS3wl9s6","uri":"spotify:track:25mjZuMkkML0LYJXfsXyi2","play_origin":"playlist"}} Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1141" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=debug msg="selected format OGG_VORBIS_320 (85e6826e5b7877f2d079904921e8fcd1b35c8d78)" uri="spotify:track:25mjZuMkkML0LYJXfsXyi2" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=debug msg="requested aes key for file 85e6826e5b7877f2d079904921e8fcd1b35c8d78, gid: 25mjZuMkkML0LYJXfsXyi2" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:25mjZuMkkML0LYJXfsXyi2" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=debug msg="fetched first chunk of 20, total size is 10153796 bytes" uri="spotify:track:25mjZuMkkML0LYJXfsXyi2" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:25mjZuMkkML0LYJXfsXyi2" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=trace msg="seek to 16846ms (diff: 140ms, samples: 742908, bytes: 601391)" uri="spotify:track:25mjZuMkkML0LYJXfsXyi2" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=debug msg="created new output device" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:25mjZuMkkML0LYJXfsXyi2" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:25mjZuMkkML0LYJXfsXyi2" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=debug msg="fetched chunk 4/19, size: 524288" uri="spotify:track:25mjZuMkkML0LYJXfsXyi2" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Feb 06 18:43:10 rivoplus go-librespot[3903]: time="2026-02-06T18:43:10+01:00" level=info msg="loaded track \"From Russia With Love - Remastered\" (paused: false, position: 16846ms, duration: 256333ms, prefetched: false)" uri="spotify:track:25mjZuMkkML0LYJXfsXyi2" Feb 06 18:43:11 rivoplus go-librespot[3903]: time="2026-02-06T18:43:11+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 06 18:43:11 rivoplus go-librespot[3903]: time="2026-02-06T18:43:11+01:00" level=trace msg="scheduling prefetch in 210s" Feb 06 18:43:11 rivoplus go-librespot[3903]: time="2026-02-06T18:43:11+01:00" level=trace msg="emitting websocket event: metadata" Feb 06 18:43:11 rivoplus go-librespot[3903]: time="2026-02-06T18:43:11+01:00" level=trace msg="emitting websocket event: active" Feb 06 18:43:11 rivoplus go-librespot[3903]: time="2026-02-06T18:43:11+01:00" level=debug msg="sending successful reply for dealer request" Feb 06 18:43:11 rivoplus volumio[3111]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:25mjZuMkkML0LYJXfsXyi2","name":"From Russia With Love - Remastered","artist_names":["Count Basie"],"album_name":"Ultra-Lounge / The Crime Scene - Volume Seven","album_cover_url":"https://i.scdn.co/image/ab67616d00001e021421891049afc12cc83016ae","position":16846,"duration":256333,"release_date":"year:1996 month:1 day:1","track_number":4,"disc_number":1}} Feb 06 18:43:11 rivoplus go-librespot[3903]: time="2026-02-06T18:43:11+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Feb 06 18:43:11 rivoplus go-librespot[3903]: time="2026-02-06T18:43:11+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 06 18:43:11 rivoplus volumio[3111]: SPOTIFY: received: {"type":"active","data":null} Feb 06 18:43:11 rivoplus volumio[3111]: info: Aligning Spotify Volume to Volumio Volume Feb 06 18:43:11 rivoplus volumio[3111]: info: CoreCommandRouter::volumioGetState Feb 06 18:43:11 rivoplus go-librespot[3903]: time="2026-02-06T18:43:11+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 06 18:43:11 rivoplus go-librespot[3903]: time="2026-02-06T18:43:11+01:00" level=trace msg="emitting websocket event: playing" Feb 06 18:43:11 rivoplus volumio[3111]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:37i9dQZF1E8IyyyS3wl9s6","uri":"spotify:track:25mjZuMkkML0LYJXfsXyi2","resume":false,"play_origin":"playlist"}} Feb 06 18:43:11 rivoplus volumio[3111]: info: Spotify is playing in volatile mode Feb 06 18:43:11 rivoplus volumio[3111]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 06 18:43:11 rivoplus volumio[3111]: SPOTIFY: UNSET VOLATILE Feb 06 18:43:11 rivoplus volumio[3111]: SPOTIFY: {"status":"pause","title":"Listen to the Music (2016 Remaster)","artist":"The Doobie Brothers","album":"Toulouse Street","albumart":"https://resources.tidal.com/images/354a8e8b/83fa/41e0/8e18/7b8702331a0e/1280x1280.jpg","uri":"","trackType":"tidal","codec":"flac","seek":120682,"duration":288,"samplerate":"192 KHz","bitdepth":"24 bit","channels":2,"random":false,"repeat":false,"repeatSingle":false,"consume":false,"volume":0,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"tidalconnect"} Feb 06 18:43:11 rivoplus volumio[3111]: info: Setting Spotify stop after unset volatile call Feb 06 18:43:11 rivoplus volumio[3111]: SPOTIFY: PUSH STATE SPOTIFY Feb 06 18:43:11 rivoplus volumio[3111]: SPOTIFY: {"status":"play","service":"spop","title":"From Russia With Love - Remastered","artist":"Count Basie","album":"Ultra-Lounge / The Crime Scene - Volume Seven","albumart":"https://i.scdn.co/image/ab67616d00001e021421891049afc12cc83016ae","uri":"spotify:track:25mjZuMkkML0LYJXfsXyi2","trackType":"spotify","seek":16846,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 06 18:43:11 rivoplus volumio[3111]: info: CoreCommandRouter::servicePushState Feb 06 18:43:11 rivoplus volumio[3111]: info: CoreStateMachine::pushState Feb 06 18:43:11 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 06 18:43:11 rivoplus volumio[3111]: info: CoreCommandRouter::volumioPushState Feb 06 18:43:11 rivoplus volumio[3111]: info: CoreCommandRouter::volumioGetState Feb 06 18:43:11 rivoplus volumio[3111]: info: MRS: Pushing multiroomSync output update for this device Feb 06 18:43:11 rivoplus volumio[3111]: info: MRS: Pushing multiroomSync output Feb 06 18:43:11 rivoplus volumio[3111]: info: Signalling Playback active due to playback status change Feb 06 18:43:11 rivoplus volumio[3111]: info: Updating RAAT Signal Path Feb 06 18:43:11 rivoplus volumio[3111]: info: MCU Signalled Playback Active Feb 06 18:43:11 rivoplus volumio[3111]: SPOTIFY: PUSH STATE SPOTIFY Feb 06 18:43:11 rivoplus volumio[3111]: SPOTIFY: {"status":"play","service":"spop","title":"From Russia With Love - Remastered","artist":"Count Basie","album":"Ultra-Lounge / The Crime Scene - Volume Seven","albumart":"https://i.scdn.co/image/ab67616d00001e021421891049afc12cc83016ae","uri":"spotify:track:25mjZuMkkML0LYJXfsXyi2","trackType":"spotify","seek":16846,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Feb 06 18:43:11 rivoplus volumio[3111]: info: CoreCommandRouter::servicePushState Feb 06 18:43:11 rivoplus volumio[3111]: info: CoreStateMachine::pushState Feb 06 18:43:11 rivoplus volumio[3111]: info: CoreCommandRouter::volumioPushState Feb 06 18:43:11 rivoplus volumio[3111]: info: CoreCommandRouter::volumioGetState Feb 06 18:43:11 rivoplus volumio[3111]: info: MRS: Pushing multiroomSync output update for this device Feb 06 18:43:11 rivoplus volumio[3111]: info: MRS: Pushing multiroomSync output Feb 06 18:43:11 rivoplus volumio[3111]: info: Signalling Playback active due to playback status change Feb 06 18:43:11 rivoplus volumio[3111]: info: Updating RAAT Signal Path Feb 06 18:43:11 rivoplus volumio[3111]: info: Spotify Stop Feb 06 18:43:11 rivoplus volumio[3111]: SPOTIFY: SPOTIFY STOP Feb 06 18:43:11 rivoplus volumio[3111]: SPOTIFY: {"status":"play","title":"From Russia With Love - Remastered","artist":"Count Basie","album":"Ultra-Lounge / The Crime Scene - Volume Seven","albumart":"https://i.scdn.co/image/ab67616d00001e021421891049afc12cc83016ae","uri":"spotify:track:25mjZuMkkML0LYJXfsXyi2","trackType":"spotify","codec":"ogg","seek":16846,"duration":256,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":0,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} Feb 06 18:43:20 rivoplus go-librespot[3903]: time="2026-02-06T18:43:20+01:00" level=trace msg="received accesspoint ping" Feb 06 18:43:20 rivoplus go-librespot[3903]: time="2026-02-06T18:43:20+01:00" level=trace msg="received accesspoint pong ack" Feb 06 18:43:20 rivoplus go-librespot[3903]: time="2026-02-06T18:43:20+01:00" level=trace msg="sent dealer ping" Feb 06 18:43:20 rivoplus go-librespot[3903]: time="2026-02-06T18:43:20+01:00" level=trace msg="received dealer pong" Feb 06 18:43:21 rivoplus go-librespot[3903]: time="2026-02-06T18:43:21+01:00" level=debug msg="fetched chunk 5/19, size: 524288" uri="spotify:track:25mjZuMkkML0LYJXfsXyi2" Feb 06 18:43:35 rivoplus go-librespot[3903]: time="2026-02-06T18:43:35+01:00" level=debug msg="fetched chunk 6/19, size: 524288" uri="spotify:track:25mjZuMkkML0LYJXfsXyi2" Feb 06 18:43:39 rivoplus volumio5-onboarding[4220]: time=2026-02-06T18:43:39.027+01:00 level=INFO msg="established new WebSocket connection" component=conn/ws remoteAddr=192.168.1.16:39762 Feb 06 18:43:39 rivoplus volumio5-onboarding[4220]: time=2026-02-06T18:43:39.053+01:00 level=INFO msg="app ready event" component=server event=CLIENT_EVENT_TYPE_APP_READY peer="192.168.1.16:39762 @ 0x28a4180" latency=-15.183254ms platform=PLATFORM_ANDROID version=5.260120.0 Feb 06 18:43:39 rivoplus volumio5-onboarding[4220]: time=2026-02-06T18:43:39.053+01:00 level=INFO msg="device data request" component=server type=REQUEST_TYPE_DEVICE_DATA peer="192.168.1.16:39762 @ 0x28a4180" latency=-16.517459ms timeout=10s Feb 06 18:43:39 rivoplus volumio[3111]: info: Received Get System Info Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 06 18:43:39 rivoplus volumio[3111]: info: Discovery: Getting this device information Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::volumioGetState Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getExtendedOutputDevices Feb 06 18:43:39 rivoplus volumio[3111]: No protocol specified Feb 06 18:43:39 rivoplus volumio[3111]: xcb_connection_has_error() returned true Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Feb 06 18:43:39 rivoplus volumio[3111]: amixer -c 5 info | grep "Comtrue-inc UAC2 Device" Feb 06 18:43:39 rivoplus volumio[3111]: No protocol specified Feb 06 18:43:39 rivoplus volumio[3111]: xcb_connection_has_error() returned true Feb 06 18:43:39 rivoplus volumio[3111]: Card hw:5 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Feb 06 18:43:39 rivoplus volumio[3111]: amixer -c 5 info | grep "Comtrue-inc UAC2 Device" Feb 06 18:43:39 rivoplus volumio[3111]: No protocol specified Feb 06 18:43:39 rivoplus volumio[3111]: xcb_connection_has_error() returned true Feb 06 18:43:39 rivoplus volumio[3111]: Card hw:5 'Device'/'Comtrue-inc Comtrue-inc UAC2 Device at usb-xhci-hcd.0.auto-1.4.3, high speed' Feb 06 18:43:39 rivoplus volumio[3111]: info: Received Get System Info Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 06 18:43:39 rivoplus volumio[3111]: info: Discovery: Getting this device information Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::volumioGetState Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::volumioGetState Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 06 18:43:39 rivoplus volumio[3111]: info: Discovery: Getting this device information Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::volumioGetState Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 06 18:43:39 rivoplus volumio[3111]: verbose: New Socket.io Connection to 192.168.1.50:3000 from 192.168.1.16 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 06 18:43:39 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 06 18:43:40 rivoplus volumio5-onboarding[4220]: time=2026-02-06T18:43:40.052+01:00 level=INFO msg="new address was allocated" component=conn/ble old=2 new=3 Feb 06 18:43:43 rivoplus volumio5-onboarding[4220]: time=2026-02-06T18:43:43.939+01:00 level=INFO msg="continue navigation request" component=server type=REQUEST_TYPE_CONTINUE_NAVIGATION peer="192.168.1.16:39762 @ 0x28a4180" latency=-15.461411ms timeout=10s from=APP_PAGE_ROOT Feb 06 18:43:45 rivoplus sudo[5193]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 06 18:43:45 rivoplus sudo[5193]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 06 18:43:45 rivoplus sudo[5193]: pam_unix(sudo:session): session closed for user root Feb 06 18:43:45 rivoplus sudo[5196]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 06 18:43:45 rivoplus sudo[5196]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 06 18:43:45 rivoplus sudo[5196]: pam_unix(sudo:session): session closed for user root Feb 06 18:43:45 rivoplus volumio[3111]: verbose: New Socket.io Connection to 192.168.1.50 from 192.168.1.16 UA: Mozilla/5.0 (Linux; Android 15; SM-A057G Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/144.0.7559.109 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Feb 06 18:43:46 rivoplus volumio[3111]: info: CoreCommandRouter::volumioGetVisibleSources Feb 06 18:43:46 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 06 18:43:46 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 06 18:43:46 rivoplus volumio[3111]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Feb 06 18:43:46 rivoplus volumio[3111]: info: CoreCommandRouter::volumioGetState Feb 06 18:43:46 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 06 18:43:46 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 06 18:43:46 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 06 18:43:46 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 06 18:43:46 rivoplus sudo[5242]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 06 18:43:46 rivoplus sudo[5242]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 06 18:43:46 rivoplus sudo[5244]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 06 18:43:46 rivoplus sudo[5244]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 06 18:43:46 rivoplus sudo[5242]: pam_unix(sudo:session): session closed for user root Feb 06 18:43:46 rivoplus sudo[5244]: pam_unix(sudo:session): session closed for user root Feb 06 18:43:46 rivoplus volumio[3111]: verbose: New Socket.io Connection to 192.168.1.50 from 192.168.1.16 UA: Mozilla/5.0 (Linux; Android 15; SM-A057G Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/144.0.7559.109 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Feb 06 18:43:46 rivoplus volumio[3111]: info: CoreCommandRouter::volumioGetState Feb 06 18:43:46 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Feb 06 18:43:46 rivoplus volumio[3111]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Feb 06 18:43:46 rivoplus volumio[3111]: info: Listing playlists Feb 06 18:43:46 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Feb 06 18:43:46 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Feb 06 18:43:46 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Feb 06 18:43:46 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 06 18:43:46 rivoplus go-librespot[3903]: time="2026-02-06T18:43:46+01:00" level=debug msg="fetched chunk 7/19, size: 524288" uri="spotify:track:25mjZuMkkML0LYJXfsXyi2" Feb 06 18:43:50 rivoplus go-librespot[3903]: time="2026-02-06T18:43:50+01:00" level=trace msg="sent dealer ping" Feb 06 18:43:50 rivoplus go-librespot[3903]: time="2026-02-06T18:43:50+01:00" level=trace msg="received dealer pong" Feb 06 18:43:54 rivoplus volumio[3111]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Feb 06 18:43:54 rivoplus volumio[3111]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Feb 06 18:43:54 rivoplus volumio[3111]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 06 18:43:54 rivoplus volumio[3111]: TypeError: Cannot read property 'then' of undefined Feb 06 18:43:54 rivoplus volumio[3111]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Feb 06 18:43:54 rivoplus volumio[3111]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2279:30) Feb 06 18:43:54 rivoplus volumio[3111]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1467:26) Feb 06 18:43:54 rivoplus volumio[3111]: at Socket.emit (events.js:400:28) Feb 06 18:43:54 rivoplus volumio[3111]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Feb 06 18:43:54 rivoplus volumio[3111]: at processTicksAndRejections (internal/process/task_queues.js:77:11) Feb 06 18:43:54 rivoplus volumio[3111]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 06 18:43:55 rivoplus sudo[5276]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-06 18:42 Feb 06 18:43:55 rivoplus sudo[5276]: 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="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="2f25e1a98e53e2dbc4f3878604e250b0379f3ea4" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="rivoplus" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 06:47:33 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Rivo Plus" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Rivo Plus" VOLUMIO_HASH="9e8aa5d6afb5e5d87a87bafae7aa5647"