Sep 03 18:46:00 mr.thnh volumio[1098]: info: Executing endpoint getSimilarArtists Sep 03 18:46:00 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Sep 03 18:46:00 mr.thnh volumio[1098]: info: Executing endpoint getSimilarArtists Sep 03 18:46:00 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Sep 03 18:46:00 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:46:00 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:46:00 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:46:00 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:46:03 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:03+07:00" level=trace msg="sent dealer ping" Sep 03 18:46:03 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:03+07:00" level=trace msg="received dealer pong" Sep 03 18:46:15 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: my_music , getSuperSearchEnabledSourcesList Sep 03 18:46:15 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioGetBrowseSources Sep 03 18:46:15 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioGetBrowseSources Sep 03 18:46:15 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Sep 03 18:46:15 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: spop , search Sep 03 18:46:16 mr.thnh volumio[1098]: info: All search sources collected, pushing search results Sep 03 18:46:16 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Sep 03 18:46:16 mr.thnh volumio[1098]: info: In handleBrowseUri, curUri=spotify:artist:2OwAXqzzxykDbPiDJjtnVo Sep 03 18:46:17 mr.thnh volumio[1098]: info: Preload queue cleared Sep 03 18:46:17 mr.thnh volumio[1098]: info: Preloading song: spotify:track:0hBscmoPoatnpb86eCpwKf Sep 03 18:46:17 mr.thnh volumio[1098]: info: Preload queue cleared Sep 03 18:46:17 mr.thnh volumio[1098]: info: Preload queue cleared Sep 03 18:46:17 mr.thnh volumio[1098]: info: Executing endpoint getSimilarArtists Sep 03 18:46:17 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Sep 03 18:46:17 mr.thnh volumio[1098]: info: Executing endpoint getSimilarArtists Sep 03 18:46:17 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Sep 03 18:46:17 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:46:17 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:46:17 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:46:17 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:46:23 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 03 18:46:23 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 03 18:46:23 mr.thnh volumio[1098]: info: Discovery: Getting this device information Sep 03 18:46:23 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioGetState Sep 03 18:46:23 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 03 18:46:25 mr.thnh volumio[1098]: info: Preload queue cleared Sep 03 18:46:25 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 03 18:46:25 mr.thnh volumio[1098]: info: CoreStateMachine::ClearQueue Sep 03 18:46:25 mr.thnh volumio[1098]: info: CoreStateMachine::stop Sep 03 18:46:25 mr.thnh volumio[1098]: info: CoreStateMachine::serviceStop Sep 03 18:46:25 mr.thnh volumio[1098]: info: CoreCommandRouter::serviceStop Sep 03 18:46:25 mr.thnh volumio[1098]: info: Airplay Stop Sep 03 18:46:25 mr.thnh volumio[1098]: info: Stopping Airplay Playback and sending pause command to client via USR2 Sep 03 18:46:25 mr.thnh volumio[1098]: info: CorePlayQueue::clearPlayQueue Sep 03 18:46:25 mr.thnh volumio[1098]: info: CorePlayQueue::saveQueue Sep 03 18:46:25 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushQueue Sep 03 18:46:25 mr.thnh volumio[1098]: info: CoreStateMachine::addQueueItems Sep 03 18:46:25 mr.thnh volumio[1098]: info: CorePlayQueue::addQueueItems Sep 03 18:46:25 mr.thnh volumio[1098]: info: Preload queue cleared Sep 03 18:46:25 mr.thnh volumio[1098]: info: Adding Item to queue: spotify:track:0hBscmoPoatnpb86eCpwKf Sep 03 18:46:25 mr.thnh volumio[1098]: info: Exploding uri spotify:track:0hBscmoPoatnpb86eCpwKf in service spop Sep 03 18:46:25 mr.thnh volumio[1098]: SPOTIFY: EXPLODING URI:spotify:track:0hBscmoPoatnpb86eCpwKf Sep 03 18:46:25 mr.thnh sudo[5957]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 3485 Sep 03 18:46:25 mr.thnh sudo[5957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 03 18:46:25 mr.thnh sudo[5957]: pam_unix(sudo:session): session closed for user root Sep 03 18:46:25 mr.thnh volumio[1098]: info: Shairport-Sync paused with USR2 Sep 03 18:46:25 mr.thnh shairport-sync[4320]: {"time":1756899371703,"response":"airplayInactive Success"} Sep 03 18:46:25 mr.thnh systemd[1]: shairport-sync.service: Main process exited, code=killed, status=12/USR2 Sep 03 18:46:25 mr.thnh systemd[1]: shairport-sync.service: Failed with result 'signal'. Sep 03 18:46:25 mr.thnh systemd[1]: shairport-sync.service: Consumed 13.380s CPU time. Sep 03 18:46:25 mr.thnh systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service... Sep 03 18:46:25 mr.thnh dbus-daemon[908]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.63' (uid=0 pid=5960 comm="timedatectl show --property=NTPSynchronized --valu") Sep 03 18:46:25 mr.thnh systemd[1]: Starting systemd-timedated.service - Time & Date Service... Sep 03 18:46:26 mr.thnh dbus-daemon[908]: [system] Successfully activated service 'org.freedesktop.timedate1' Sep 03 18:46:26 mr.thnh systemd[1]: Started systemd-timedated.service - Time & Date Service. Sep 03 18:46:26 mr.thnh setdatetime-helper.sh[5959]: Time is already synchronized. Sep 03 18:46:26 mr.thnh systemd[1]: setdatetime-helper.timer.service: Deactivated successfully. Sep 03 18:46:26 mr.thnh systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service. Sep 03 18:46:26 mr.thnh volumio[1098]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","service":"spop","name":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","type":"song","duration":253,"albumart":"https://i.scdn.co/image/ab67616d0000b273a9bbb560377f13c33f54ea15","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 03 18:46:26 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushQueue Sep 03 18:46:26 mr.thnh volumio[1098]: info: CorePlayQueue::saveQueue Sep 03 18:46:26 mr.thnh volumio[1098]: info: CoreStateMachine::updateTrackBlock Sep 03 18:46:26 mr.thnh volumio[1098]: info: CorePlayQueue::getTrackBlock Sep 03 18:46:26 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPlay Sep 03 18:46:26 mr.thnh volumio[1098]: verbose: UNSET VOLATILE: Service: airplay_emulation Sep 03 18:46:26 mr.thnh volumio[1098]: info: Stopping Airplay Playback and sending pause command to client via USR2 Sep 03 18:46:26 mr.thnh volumio[1098]: info: CoreStateMachine::play index 0 Sep 03 18:46:26 mr.thnh volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 18:46:26 mr.thnh volumio[1098]: info: CoreStateMachine::stop Sep 03 18:46:26 mr.thnh volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 18:46:26 mr.thnh volumio[1098]: info: CoreStateMachine::play index undefined Sep 03 18:46:26 mr.thnh volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 18:46:26 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:46:26 mr.thnh volumio[1098]: info: CoreStateMachine::startPlaybackTimer Sep 03 18:46:26 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:46:26 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioGetVisibleSources Sep 03 18:46:26 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 03 18:46:26 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Sep 03 18:46:26 mr.thnh volumio[1098]: info: [1756899986176] ControllerSpotify::clearAddPlayTrack Sep 03 18:46:26 mr.thnh volumio[1098]: info: Sending Spotify command with payload to local API: /player/play Sep 03 18:46:26 mr.thnh sudo[5966]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 Sep 03 18:46:26 mr.thnh sudo[5966]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 03 18:46:26 mr.thnh sudo[5966]: pam_unix(sudo:session): session closed for user root Sep 03 18:46:26 mr.thnh volumio[1098]: info: Cannot execute Shairport-sync USR2 kill: Error: Command failed: /usr/bin/sudo /bin/kill -USR2 $(pidof shairport-sync) Sep 03 18:46:26 mr.thnh volumio[1098]: Usage: Sep 03 18:46:26 mr.thnh volumio[1098]: kill [options] [...] Sep 03 18:46:26 mr.thnh volumio[1098]: Options: Sep 03 18:46:26 mr.thnh volumio[1098]: [...] send signal to every listed Sep 03 18:46:26 mr.thnh volumio[1098]: -, -s, --signal Sep 03 18:46:26 mr.thnh volumio[1098]: specify the to be sent Sep 03 18:46:26 mr.thnh volumio[1098]: -q, --queue integer value to be sent with the signal Sep 03 18:46:26 mr.thnh volumio[1098]: -l, --list=[] list all signal names, or convert one to a name Sep 03 18:46:26 mr.thnh volumio[1098]: -L, --table list all signal names in a nice table Sep 03 18:46:26 mr.thnh volumio[1098]: -h, --help display this help and exit Sep 03 18:46:26 mr.thnh volumio[1098]: -V, --version output version information and exit Sep 03 18:46:26 mr.thnh volumio[1098]: For more details see kill(1). Sep 03 18:46:26 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:26+07:00" level=debug msg="resolved context of track" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:46:26 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:26+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:46:26 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:26+07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:46:26 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:26+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 03 18:46:26 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:26+07:00" level=trace msg="emitting websocket event: will_play" Sep 03 18:46:26 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","play_origin":"go-librespot"}} Sep 03 18:46:26 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","play_origin":"go-librespot"}} Sep 03 18:46:26 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:26+07:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Sep 03 18:46:26 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:26+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 242" Sep 03 18:46:26 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:26+07:00" level=debug msg="selected format OGG_VORBIS_320 (3260dff04477f1a2f7c01262ebba6fbc36cadd2b)" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:46:26 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:26+07:00" level=debug msg="requested aes key for file 3260dff04477f1a2f7c01262ebba6fbc36cadd2b, gid: 0hBscmoPoatnpb86eCpwKf" Sep 03 18:46:26 mr.thnh volumio[1098]: info: Restarting Shairport-Sync after stop Sep 03 18:46:27 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:27+07:00" level=trace msg="found 2 cdn urls" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:46:27 mr.thnh sudo[5969]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Sep 03 18:46:27 mr.thnh sudo[5969]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Sep 03 18:46:27 mr.thnh systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Sep 03 18:46:27 mr.thnh sudo[5969]: pam_unix(sudo:session): session closed for user root Sep 03 18:46:27 mr.thnh volumio[1098]: info: Shairport-Sync retarted Sep 03 18:46:29 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:29+07:00" level=debug msg="fetched first chunk of 18, total size is 9003732 bytes" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:46:29 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:29+07:00" level=debug msg="created new output device" Sep 03 18:46:29 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:29+07: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" Sep 03 18:46:29 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:29+07:00" level=info msg="loaded track \"Giấc Mơ Thôi\" (paused: false, position: 0ms, duration: 253260ms, prefetched: false)" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:46:29 mr.thnh volumio[1098]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Sep 03 18:46:29 mr.thnh volumio[1098]: info: FusionDsp - ---- read samplerate from file: 44100 Sep 03 18:46:29 mr.thnh volumio[1098]: error: FusionDsp - File size not found in array! Sep 03 18:46:29 mr.thnh volumio[1098]: info: FusionDsp - Nulleq applied Sep 03 18:46:29 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:29+07:00" level=debug msg="fetched chunk 2/17, size: 524288" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:46:29 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:29+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 03 18:46:29 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:29+07:00" level=trace msg="scheduling prefetch in 223s" Sep 03 18:46:29 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:29+07:00" level=trace msg="emitting websocket event: metadata" Sep 03 18:46:29 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","name":"Giấc Mơ Thôi","artist_names":["Vo Le Vy"],"album_name":"Giấc Mơ Thôi","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","position":0,"duration":253260,"release_date":"year:2020 month:9 day:16","track_number":1,"disc_number":1}} Sep 03 18:46:29 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","name":"Giấc Mơ Thôi","artist_names":["Vo Le Vy"],"album_name":"Giấc Mơ Thôi","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","position":0,"duration":253260,"release_date":"year:2020 month:9 day:16","track_number":1,"disc_number":1}} Sep 03 18:46:29 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:29+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 03 18:46:29 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:29+07:00" level=trace msg="emitting websocket event: playing" Sep 03 18:46:29 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","resume":false,"play_origin":"go-librespot"}} Sep 03 18:46:29 mr.thnh volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Sep 03 18:46:29 mr.thnh volumio[1098]: SPOTIFY: {"status":"play","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":0,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreCommandRouter::servicePushState Sep 03 18:46:29 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:46:29 mr.thnh volumio[1098]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":0,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:46:29 mr.thnh volumio[1098]: verbose: CURRENT POSITION 0 Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreStateMachine::syncState stateService play Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreStateMachine::syncState currentStatus stop Sep 03 18:46:29 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","resume":false,"play_origin":"go-librespot"}} Sep 03 18:46:29 mr.thnh volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Sep 03 18:46:29 mr.thnh volumio[1098]: SPOTIFY: {"status":"play","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":0,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreCommandRouter::servicePushState Sep 03 18:46:29 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:46:29 mr.thnh volumio[1098]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":0,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:46:29 mr.thnh volumio[1098]: verbose: CURRENT POSITION 0 Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreStateMachine::syncState stateService play Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreStateMachine::syncState currentStatus play Sep 03 18:46:29 mr.thnh volumio[1098]: info: Received an update from plugin. extracting info from payload Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:46:29 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:46:29 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:46:29 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:46:29 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:46:29 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:46:29 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:46:29 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:46:29 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:46:29 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:46:29 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:46:29 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:46:29 mr.thnh volumio[1098]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Sep 03 18:46:29 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:46:29 mr.thnh volumio[1098]: info: FusionDsp - Clipping Monitor started Sep 03 18:46:29 mr.thnh volumio[1098]: info: FusionDsp - Clipping Monitor started Sep 03 18:46:29 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:29+07:00" level=debug msg="fetched chunk 3/17, size: 524288" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:46:29 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:29+07:00" level=debug msg="fetched chunk 1/17, size: 524288" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:46:29 mr.thnh volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Sep 03 18:46:29 mr.thnh volumio[1098]: SPOTIFY: {"status":"play","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":0,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreCommandRouter::servicePushState Sep 03 18:46:29 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:46:29 mr.thnh volumio[1098]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":0,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:46:29 mr.thnh volumio[1098]: verbose: CURRENT POSITION 0 Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreStateMachine::syncState stateService play Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreStateMachine::syncState currentStatus play Sep 03 18:46:29 mr.thnh volumio[1098]: info: Received an update from plugin. extracting info from payload Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:46:29 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:46:29 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:46:29 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:46:29 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:46:29 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:46:29 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:46:29 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:46:29 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:46:29 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:46:29 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:46:29 mr.thnh volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Sep 03 18:46:29 mr.thnh volumio[1098]: SPOTIFY: {"status":"play","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":0,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreCommandRouter::servicePushState Sep 03 18:46:29 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:46:29 mr.thnh volumio[1098]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":0,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:46:29 mr.thnh volumio[1098]: verbose: CURRENT POSITION 0 Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreStateMachine::syncState stateService play Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreStateMachine::syncState currentStatus play Sep 03 18:46:29 mr.thnh volumio[1098]: info: Received an update from plugin. extracting info from payload Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:46:29 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:46:29 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:46:29 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:46:29 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:46:29 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:46:29 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:46:29 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:46:29 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:46:29 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:46:29 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:46:29 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:46:29 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:46:29 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:46:29 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:46:29 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:46:31 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:46:31 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:46:31 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:46:31 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:46:31 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:46:31 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:46:32 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:32+07:00" level=trace msg="received accesspoint ping" Sep 03 18:46:33 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:33+07:00" level=trace msg="received accesspoint pong ack" Sep 03 18:46:33 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:33+07:00" level=trace msg="sent dealer ping" Sep 03 18:46:33 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:33+07:00" level=trace msg="received dealer pong" Sep 03 18:46:42 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:42+07:00" level=debug msg="fetched chunk 4/17, size: 524288" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:46:53 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 03 18:46:53 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 03 18:46:53 mr.thnh volumio[1098]: info: Discovery: Getting this device information Sep 03 18:46:53 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioGetState Sep 03 18:46:53 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:46:53 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 03 18:46:56 mr.thnh systemd[1]: systemd-timedated.service: Deactivated successfully. Sep 03 18:46:58 mr.thnh go-librespot[5345]: time="2025-09-03T18:46:58+07:00" level=debug msg="fetched chunk 5/17, size: 524288" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:47:03 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:03+07:00" level=trace msg="sent dealer ping" Sep 03 18:47:03 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:03+07:00" level=trace msg="received dealer pong" Sep 03 18:47:09 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Sep 03 18:47:09 mr.thnh volumio[1098]: info: In handleBrowseUri, curUri=spotify:album:3etRQCL3lOSrEWJiMzTTAI Sep 03 18:47:10 mr.thnh volumio[1098]: info: Preload queue cleared Sep 03 18:47:10 mr.thnh volumio[1098]: info: Executing endpoint getSimilarAlbums Sep 03 18:47:10 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Sep 03 18:47:10 mr.thnh volumio[1098]: info: Executing endpoint getSimilarAlbums Sep 03 18:47:10 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarAlbums Sep 03 18:47:10 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:47:10 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:47:10 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:47:10 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:47:10 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:47:10 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:47:10 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:47:10 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:47:13 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:13+07:00" level=debug msg="fetched chunk 6/17, size: 524288" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:47:15 mr.thnh volumio[1098]: info: Preload queue cleared Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::ClearQueue Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::stop Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::stPlaybackTimer Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::updateTrackBlock Sep 03 18:47:15 mr.thnh volumio[1098]: info: CorePlayQueue::getTrackBlock Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:15 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:15 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:15 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:15 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:15 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::serviceStop Sep 03 18:47:15 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreCommandRouter::serviceStop Sep 03 18:47:15 mr.thnh volumio[1098]: info: Spotify Stop Sep 03 18:47:15 mr.thnh volumio[1098]: SPOTIFY: SPOTIFY STOP Sep 03 18:47:15 mr.thnh volumio[1098]: SPOTIFY: {"status":"play","position":0,"title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d0000b273a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","codec":"ogg","seek":0,"duration":253,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Sep 03 18:47:15 mr.thnh volumio[1098]: info: Sending Spotify command to local API: /player/pause Sep 03 18:47:15 mr.thnh volumio[1098]: info: CorePlayQueue::clearPlayQueue Sep 03 18:47:15 mr.thnh volumio[1098]: info: CorePlayQueue::saveQueue Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushQueue Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::addQueueItems Sep 03 18:47:15 mr.thnh volumio[1098]: info: CorePlayQueue::addQueueItems Sep 03 18:47:15 mr.thnh volumio[1098]: info: Preload queue cleared Sep 03 18:47:15 mr.thnh volumio[1098]: info: Adding Item to queue: spotify:album:3etRQCL3lOSrEWJiMzTTAI Sep 03 18:47:15 mr.thnh volumio[1098]: info: Exploding uri spotify:album:3etRQCL3lOSrEWJiMzTTAI in service spop Sep 03 18:47:15 mr.thnh volumio[1098]: SPOTIFY: EXPLODING URI:spotify:album:3etRQCL3lOSrEWJiMzTTAI Sep 03 18:47:15 mr.thnh volumio[1098]: info: FusionDsp - Volumio is not playing Sep 03 18:47:15 mr.thnh volumio[1098]: info: FusionDsp - Clipped samples monitor stopped Sep 03 18:47:15 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:15+07:00" level=debug msg="pause track at 47364ms" Sep 03 18:47:15 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:15+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 03 18:47:15 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:15+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 03 18:47:15 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:15+07:00" level=trace msg="emitting websocket event: paused" Sep 03 18:47:15 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","play_origin":"go-librespot"}} Sep 03 18:47:15 mr.thnh volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Sep 03 18:47:15 mr.thnh volumio[1098]: SPOTIFY: {"status":"pause","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":46000,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreCommandRouter::servicePushState Sep 03 18:47:15 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:15 mr.thnh volumio[1098]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":46000,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:15 mr.thnh volumio[1098]: verbose: CURRENT POSITION 0 Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::syncState stateService pause Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::syncState currentStatus stop Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:15 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:15 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:15 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:15 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:15 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:15 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","play_origin":"go-librespot"}} Sep 03 18:47:15 mr.thnh volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Sep 03 18:47:15 mr.thnh volumio[1098]: SPOTIFY: {"status":"pause","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":46000,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreCommandRouter::servicePushState Sep 03 18:47:15 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:15 mr.thnh volumio[1098]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":46000,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:15 mr.thnh volumio[1098]: verbose: CURRENT POSITION 0 Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::syncState stateService pause Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::syncState currentStatus stop Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:15 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:15 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:15 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:15 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:15 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:15 mr.thnh volumio[1098]: info: FusionDsp - Volumio is not playing Sep 03 18:47:15 mr.thnh volumio[1098]: info: FusionDsp - Clipped samples monitor stopped Sep 03 18:47:15 mr.thnh volumio[1098]: info: FusionDsp - Volumio is not playing Sep 03 18:47:15 mr.thnh volumio[1098]: info: FusionDsp - Clipped samples monitor stopped Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushQueue Sep 03 18:47:15 mr.thnh volumio[1098]: info: CorePlayQueue::saveQueue Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::updateTrackBlock Sep 03 18:47:15 mr.thnh volumio[1098]: info: CorePlayQueue::getTrackBlock Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPlay Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::play index 0 Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::stop Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::play index undefined Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 18:47:15 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreStateMachine::startPlaybackTimer Sep 03 18:47:15 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioGetVisibleSources Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 03 18:47:15 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Sep 03 18:47:15 mr.thnh volumio[1098]: info: [1756900035856] ControllerSpotify::clearAddPlayTrack Sep 03 18:47:15 mr.thnh volumio[1098]: info: Sending Spotify command with payload to local API: /player/play Sep 03 18:47:15 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:15+07:00" level=debug msg="resolved context of track" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:47:15 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:15+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:47:15 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:15+07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:47:16 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:16+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 03 18:47:16 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:16+07:00" level=trace msg="emitting websocket event: will_play" Sep 03 18:47:16 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","play_origin":"go-librespot"}} Sep 03 18:47:16 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","play_origin":"go-librespot"}} Sep 03 18:47:16 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:16+07:00" level=debug msg="selected format OGG_VORBIS_320 (3260dff04477f1a2f7c01262ebba6fbc36cadd2b)" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:47:16 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:16+07:00" level=debug msg="requested aes key for file 3260dff04477f1a2f7c01262ebba6fbc36cadd2b, gid: 0hBscmoPoatnpb86eCpwKf" Sep 03 18:47:16 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:16+07:00" level=trace msg="found 2 cdn urls" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:47:16 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:16+07:00" level=debug msg="fetched first chunk of 18, total size is 9003732 bytes" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:47:16 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:16+07: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" Sep 03 18:47:16 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:16+07:00" level=info msg="loaded track \"Giấc Mơ Thôi\" (paused: false, position: 0ms, duration: 253260ms, prefetched: false)" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:47:16 mr.thnh volumio[1098]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Sep 03 18:47:16 mr.thnh volumio[1098]: info: FusionDsp - ---- read samplerate from file: 44100 Sep 03 18:47:16 mr.thnh volumio[1098]: error: FusionDsp - File size not found in array! Sep 03 18:47:16 mr.thnh volumio[1098]: info: FusionDsp - Nulleq applied Sep 03 18:47:16 mr.thnh volumio[1098]: error: FusionDsp - Reload WebSocket error: [object Object] Sep 03 18:47:16 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:16+07:00" level=debug msg="fetched chunk 1/17, size: 524288" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:47:16 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:16+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 03 18:47:16 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:16+07:00" level=trace msg="scheduling prefetch in 223s" Sep 03 18:47:16 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:16+07:00" level=trace msg="emitting websocket event: metadata" Sep 03 18:47:16 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","name":"Giấc Mơ Thôi","artist_names":["Vo Le Vy"],"album_name":"Giấc Mơ Thôi","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","position":0,"duration":253260,"release_date":"year:2020 month:9 day:16","track_number":1,"disc_number":1}} Sep 03 18:47:16 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","name":"Giấc Mơ Thôi","artist_names":["Vo Le Vy"],"album_name":"Giấc Mơ Thôi","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","position":0,"duration":253260,"release_date":"year:2020 month:9 day:16","track_number":1,"disc_number":1}} Sep 03 18:47:16 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:16+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 03 18:47:16 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:16+07:00" level=trace msg="emitting websocket event: playing" Sep 03 18:47:16 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","resume":false,"play_origin":"go-librespot"}} Sep 03 18:47:16 mr.thnh volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Sep 03 18:47:16 mr.thnh volumio[1098]: SPOTIFY: {"status":"play","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":0,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:16 mr.thnh volumio[1098]: info: CoreCommandRouter::servicePushState Sep 03 18:47:16 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:16 mr.thnh volumio[1098]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":0,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:16 mr.thnh volumio[1098]: verbose: CURRENT POSITION 0 Sep 03 18:47:16 mr.thnh volumio[1098]: info: CoreStateMachine::syncState stateService play Sep 03 18:47:16 mr.thnh volumio[1098]: info: CoreStateMachine::syncState currentStatus stop Sep 03 18:47:16 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","resume":false,"play_origin":"go-librespot"}} Sep 03 18:47:16 mr.thnh volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Sep 03 18:47:16 mr.thnh volumio[1098]: SPOTIFY: {"status":"play","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":0,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:16 mr.thnh volumio[1098]: info: CoreCommandRouter::servicePushState Sep 03 18:47:16 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:16 mr.thnh volumio[1098]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":0,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:16 mr.thnh volumio[1098]: verbose: CURRENT POSITION 0 Sep 03 18:47:16 mr.thnh volumio[1098]: info: CoreStateMachine::syncState stateService play Sep 03 18:47:16 mr.thnh volumio[1098]: info: CoreStateMachine::syncState currentStatus play Sep 03 18:47:16 mr.thnh volumio[1098]: info: Received an update from plugin. extracting info from payload Sep 03 18:47:16 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:16 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:16 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 18:47:16 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:16 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:16 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:16 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:16 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:16 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:16 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:16 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:16 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:16 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:16 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:16 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:16 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:47:16 mr.thnh volumio[1098]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Sep 03 18:47:16 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:47:16 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:16 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:16 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:16+07:00" level=debug msg="fetched chunk 3/17, size: 524288" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:47:17 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:17+07:00" level=debug msg="fetched chunk 2/17, size: 524288" uri="spotify:track:0hBscmoPoatnpb86eCpwKf" Sep 03 18:47:17 mr.thnh volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Sep 03 18:47:17 mr.thnh volumio[1098]: SPOTIFY: {"status":"play","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":0,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:17 mr.thnh volumio[1098]: info: CoreCommandRouter::servicePushState Sep 03 18:47:17 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:17 mr.thnh volumio[1098]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":0,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:17 mr.thnh volumio[1098]: verbose: CURRENT POSITION 0 Sep 03 18:47:17 mr.thnh volumio[1098]: info: CoreStateMachine::syncState stateService play Sep 03 18:47:17 mr.thnh volumio[1098]: info: CoreStateMachine::syncState currentStatus play Sep 03 18:47:17 mr.thnh volumio[1098]: info: Received an update from plugin. extracting info from payload Sep 03 18:47:17 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:17 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:17 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:17 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:17 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:17 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:17 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:17 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:17 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:17 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:17 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:17 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:17 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:17 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:17 mr.thnh volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Sep 03 18:47:17 mr.thnh volumio[1098]: SPOTIFY: {"status":"play","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":0,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:17 mr.thnh volumio[1098]: info: CoreCommandRouter::servicePushState Sep 03 18:47:17 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:17 mr.thnh volumio[1098]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":0,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:17 mr.thnh volumio[1098]: verbose: CURRENT POSITION 0 Sep 03 18:47:17 mr.thnh volumio[1098]: info: CoreStateMachine::syncState stateService play Sep 03 18:47:17 mr.thnh volumio[1098]: info: CoreStateMachine::syncState currentStatus play Sep 03 18:47:17 mr.thnh volumio[1098]: info: Received an update from plugin. extracting info from payload Sep 03 18:47:17 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:17 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:17 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:17 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:17 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:17 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:17 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:17 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:17 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:17 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:17 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:17 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:17 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:17 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:17 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:47:17 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:47:17 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:47:17 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:47:17 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:17 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:17 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:17 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:17 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:17 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:17 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:17 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 7.2698e-05 s, 901 MB/s Sep 03 18:47:18 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:18 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:18 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:18 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 8.4427e-05 s, 776 MB/s Sep 03 18:47:18 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:47:18 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:47:18 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:47:18 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:47:18 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:47:18 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:47:18 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:18 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:19 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:19 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:19 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:19 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:19 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:19 mr.thnh volumio[1098]: 1+1 records in Sep 03 18:47:19 mr.thnh volumio[1098]: 1+1 records out Sep 03 18:47:19 mr.thnh volumio[1098]: 61712 bytes (62 kB, 60 KiB) copied, 8.0202e-05 s, 769 MB/s Sep 03 18:47:20 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:20 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:20 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:20 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 8.8933e-05 s, 737 MB/s Sep 03 18:47:20 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:20 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:21 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:21 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:21 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:21 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:21 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:21 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:21 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:21 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 7.7646e-05 s, 844 MB/s Sep 03 18:47:22 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:22 mr.thnh volumio[1098]: 1+1 records in Sep 03 18:47:22 mr.thnh volumio[1098]: 1+1 records out Sep 03 18:47:22 mr.thnh volumio[1098]: 61712 bytes (62 kB, 60 KiB) copied, 9.6914e-05 s, 637 MB/s Sep 03 18:47:22 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:22 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:23 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:23 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:23 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:23 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:23 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:23 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:23 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:23 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 7.8084e-05 s, 839 MB/s Sep 03 18:47:23 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Sep 03 18:47:23 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Sep 03 18:47:23 mr.thnh volumio[1098]: info: Discovery: Getting this device information Sep 03 18:47:23 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioGetState Sep 03 18:47:23 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:23 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Sep 03 18:47:24 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:24 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:24 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:24 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 7.7184e-05 s, 849 MB/s Sep 03 18:47:24 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:24 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:25 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:25 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:25 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:25 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:25 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:25 mr.thnh volumio[1098]: 1+1 records in Sep 03 18:47:25 mr.thnh volumio[1098]: 1+1 records out Sep 03 18:47:25 mr.thnh volumio[1098]: 61712 bytes (62 kB, 60 KiB) copied, 8.5345e-05 s, 723 MB/s Sep 03 18:47:26 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:26 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:26 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:26 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 7.7733e-05 s, 843 MB/s Sep 03 18:47:26 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:26 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:27 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:27 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:27 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:27 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:27 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:27 mr.thnh volumio[1098]: 1+1 records in Sep 03 18:47:27 mr.thnh volumio[1098]: 1+1 records out Sep 03 18:47:27 mr.thnh volumio[1098]: 61712 bytes (62 kB, 60 KiB) copied, 7.5705e-05 s, 815 MB/s Sep 03 18:47:28 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:28 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:28 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:28 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 7.7847e-05 s, 842 MB/s Sep 03 18:47:28 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:28 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:29 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:29 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:29 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:29 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:29 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:29 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:29 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:29 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 8.6528e-05 s, 757 MB/s Sep 03 18:47:29 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Sep 03 18:47:29 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: spop , search Sep 03 18:47:30 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:30 mr.thnh volumio[1098]: 1+1 records in Sep 03 18:47:30 mr.thnh volumio[1098]: 1+1 records out Sep 03 18:47:30 mr.thnh volumio[1098]: 61712 bytes (62 kB, 60 KiB) copied, 8.4082e-05 s, 734 MB/s Sep 03 18:47:30 mr.thnh volumio[1098]: info: All search sources collected, pushing search results Sep 03 18:47:30 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Sep 03 18:47:30 mr.thnh volumio[1098]: info: In handleBrowseUri, curUri=spotify:artist:0KWdVd7ZYhtlm0CLHIFBya Sep 03 18:47:30 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:30 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:31 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:31 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:31 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:31 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:31 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:31 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:31 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:31 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 8.8209e-05 s, 743 MB/s Sep 03 18:47:31 mr.thnh volumio[1098]: info: Preload queue cleared Sep 03 18:47:31 mr.thnh volumio[1098]: info: Preloading song: spotify:track:5OrpSDeWfWr33q0a5Ydfhr Sep 03 18:47:31 mr.thnh volumio[1098]: info: Preloading song: spotify:track:5JTZCDMaElB4ZBJc41YhMB Sep 03 18:47:31 mr.thnh volumio[1098]: info: Preloading song: spotify:track:6VHCSC1ofv6erC0rmvvPrj Sep 03 18:47:31 mr.thnh volumio[1098]: info: Preloading song: spotify:track:5ghwPzuXDM7mYScuNy5nZY Sep 03 18:47:31 mr.thnh volumio[1098]: info: Preloading song: spotify:track:2qxeAIiuFJRpxQpJGVbHWP Sep 03 18:47:31 mr.thnh volumio[1098]: info: Preloading song: spotify:track:3nojBsmTikUgDWOXbndv12 Sep 03 18:47:31 mr.thnh volumio[1098]: info: Preloading song: spotify:track:4dMjHsWm4Nt2Gzw5j6KXM9 Sep 03 18:47:31 mr.thnh volumio[1098]: info: Preloading song: spotify:track:3e8hAZfzqUx9RTq3uBL5nB Sep 03 18:47:31 mr.thnh volumio[1098]: info: Preloading song: spotify:track:5Gp9vCbQFiCAYhjiVXXgmz Sep 03 18:47:31 mr.thnh volumio[1098]: info: Preloading song: spotify:track:17DzRY10Qlk078arLL3isJ Sep 03 18:47:31 mr.thnh volumio[1098]: info: Preload queue cleared Sep 03 18:47:31 mr.thnh volumio[1098]: info: Preload queue cleared Sep 03 18:47:32 mr.thnh volumio[1098]: info: Executing endpoint getSimilarArtists Sep 03 18:47:32 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Sep 03 18:47:32 mr.thnh volumio[1098]: info: Executing endpoint getSimilarArtists Sep 03 18:47:32 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Sep 03 18:47:32 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:47:32 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:47:32 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:47:32 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:47:32 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:32 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:32 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:32 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 7.4441e-05 s, 880 MB/s Sep 03 18:47:32 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:32 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:33 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:33 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:33 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:33 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:33 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:33+07:00" level=trace msg="sent dealer ping" Sep 03 18:47:33 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:33+07:00" level=trace msg="received dealer pong" Sep 03 18:47:33 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:33 mr.thnh volumio[1098]: 1+1 records in Sep 03 18:47:33 mr.thnh volumio[1098]: 1+1 records out Sep 03 18:47:33 mr.thnh volumio[1098]: 61712 bytes (62 kB, 60 KiB) copied, 8.4219e-05 s, 733 MB/s Sep 03 18:47:34 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:34 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:34 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:34 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 8.1579e-05 s, 803 MB/s Sep 03 18:47:34 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:34 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:35 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:35 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:35 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:35 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:35 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:35 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:35 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:35 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 7.838e-05 s, 836 MB/s Sep 03 18:47:35 mr.thnh volumio[1098]: info: Preload queue cleared Sep 03 18:47:35 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioReplaceandPlayItems Sep 03 18:47:35 mr.thnh volumio[1098]: info: CoreStateMachine::ClearQueue Sep 03 18:47:35 mr.thnh volumio[1098]: info: CoreStateMachine::stop Sep 03 18:47:35 mr.thnh volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 18:47:35 mr.thnh volumio[1098]: info: CoreStateMachine::stPlaybackTimer Sep 03 18:47:35 mr.thnh volumio[1098]: info: CoreStateMachine::updateTrackBlock Sep 03 18:47:35 mr.thnh volumio[1098]: info: CorePlayQueue::getTrackBlock Sep 03 18:47:35 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:35 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:35 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 18:47:35 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:35 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:35 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:35 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:35 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:35 mr.thnh volumio[1098]: info: CoreStateMachine::serviceStop Sep 03 18:47:35 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:35 mr.thnh volumio[1098]: info: CoreCommandRouter::serviceStop Sep 03 18:47:35 mr.thnh volumio[1098]: info: Spotify Stop Sep 03 18:47:35 mr.thnh volumio[1098]: SPOTIFY: SPOTIFY STOP Sep 03 18:47:35 mr.thnh volumio[1098]: SPOTIFY: {"status":"play","position":0,"title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d0000b273a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","codec":"ogg","seek":0,"duration":253,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Sep 03 18:47:35 mr.thnh volumio[1098]: info: Sending Spotify command to local API: /player/pause Sep 03 18:47:35 mr.thnh volumio[1098]: info: CorePlayQueue::clearPlayQueue Sep 03 18:47:35 mr.thnh volumio[1098]: info: CorePlayQueue::saveQueue Sep 03 18:47:35 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushQueue Sep 03 18:47:35 mr.thnh volumio[1098]: info: CoreStateMachine::addQueueItems Sep 03 18:47:35 mr.thnh volumio[1098]: info: CorePlayQueue::addQueueItems Sep 03 18:47:35 mr.thnh volumio[1098]: info: Preload queue cleared Sep 03 18:47:35 mr.thnh volumio[1098]: info: Adding Item to queue: spotify:track:5OrpSDeWfWr33q0a5Ydfhr Sep 03 18:47:35 mr.thnh volumio[1098]: info: Exploding uri spotify:track:5OrpSDeWfWr33q0a5Ydfhr in service spop Sep 03 18:47:35 mr.thnh volumio[1098]: SPOTIFY: EXPLODING URI:spotify:track:5OrpSDeWfWr33q0a5Ydfhr Sep 03 18:47:35 mr.thnh volumio[1098]: info: FusionDsp - Volumio is not playing Sep 03 18:47:35 mr.thnh volumio[1098]: info: FusionDsp - Clipped samples monitor stopped Sep 03 18:47:35 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:35+07:00" level=debug msg="pause track at 3657ms" Sep 03 18:47:35 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:35+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 03 18:47:36 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:36+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 03 18:47:36 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:36+07:00" level=trace msg="emitting websocket event: paused" Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","play_origin":"go-librespot"}} Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: {"status":"pause","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":19000,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreCommandRouter::servicePushState Sep 03 18:47:36 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:36 mr.thnh volumio[1098]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":19000,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:36 mr.thnh volumio[1098]: verbose: CURRENT POSITION 0 Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreStateMachine::syncState stateService pause Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreStateMachine::syncState currentStatus stop Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:36 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:36 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:36 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:36 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:36 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","play_origin":"go-librespot"}} Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: {"status":"pause","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":19000,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreCommandRouter::servicePushState Sep 03 18:47:36 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:36 mr.thnh volumio[1098]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Giấc Mơ Thôi","artist":"Vo Le Vy","album":"Giấc Mơ Thôi","albumart":"https://i.scdn.co/image/ab67616d00001e02a9bbb560377f13c33f54ea15","uri":"spotify:track:0hBscmoPoatnpb86eCpwKf","trackType":"spotify","seek":19000,"duration":253,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:36 mr.thnh volumio[1098]: verbose: CURRENT POSITION 0 Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreStateMachine::syncState stateService pause Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreStateMachine::syncState currentStatus stop Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:36 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:36 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:36 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:36 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:36 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:36 mr.thnh volumio[1098]: info: FusionDsp - Volumio is not playing Sep 03 18:47:36 mr.thnh volumio[1098]: info: FusionDsp - Clipped samples monitor stopped Sep 03 18:47:36 mr.thnh volumio[1098]: info: FusionDsp - Volumio is not playing Sep 03 18:47:36 mr.thnh volumio[1098]: info: FusionDsp - Clipped samples monitor stopped Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5OrpSDeWfWr33q0a5Ydfhr","service":"spop","name":"MẸ YÊU CON","artist":"Cường Seven","album":"Anh Trai Vượt Ngàn Chông Gai 2024 - Chung Kết","type":"song","duration":305,"albumart":"https://i.scdn.co/image/ab67616d0000b2737ffd0c4e33388522e19adaee","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushQueue Sep 03 18:47:36 mr.thnh volumio[1098]: info: CorePlayQueue::saveQueue Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreStateMachine::updateTrackBlock Sep 03 18:47:36 mr.thnh volumio[1098]: info: CorePlayQueue::getTrackBlock Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPlay Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreStateMachine::play index 0 Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreStateMachine::addQueueItems Sep 03 18:47:36 mr.thnh volumio[1098]: info: CorePlayQueue::addQueueItems Sep 03 18:47:36 mr.thnh volumio[1098]: info: Preload queue cleared Sep 03 18:47:36 mr.thnh volumio[1098]: info: Adding Item to queue: spotify:track:5JTZCDMaElB4ZBJc41YhMB Sep 03 18:47:36 mr.thnh volumio[1098]: info: Exploding uri spotify:track:5JTZCDMaElB4ZBJc41YhMB in service spop Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: EXPLODING URI:spotify:track:5JTZCDMaElB4ZBJc41YhMB Sep 03 18:47:36 mr.thnh volumio[1098]: info: Adding Item to queue: spotify:track:6VHCSC1ofv6erC0rmvvPrj Sep 03 18:47:36 mr.thnh volumio[1098]: info: Exploding uri spotify:track:6VHCSC1ofv6erC0rmvvPrj in service spop Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: EXPLODING URI:spotify:track:6VHCSC1ofv6erC0rmvvPrj Sep 03 18:47:36 mr.thnh volumio[1098]: info: Adding Item to queue: spotify:track:5ghwPzuXDM7mYScuNy5nZY Sep 03 18:47:36 mr.thnh volumio[1098]: info: Exploding uri spotify:track:5ghwPzuXDM7mYScuNy5nZY in service spop Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: EXPLODING URI:spotify:track:5ghwPzuXDM7mYScuNy5nZY Sep 03 18:47:36 mr.thnh volumio[1098]: info: Adding Item to queue: spotify:track:2qxeAIiuFJRpxQpJGVbHWP Sep 03 18:47:36 mr.thnh volumio[1098]: info: Exploding uri spotify:track:2qxeAIiuFJRpxQpJGVbHWP in service spop Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: EXPLODING URI:spotify:track:2qxeAIiuFJRpxQpJGVbHWP Sep 03 18:47:36 mr.thnh volumio[1098]: info: Adding Item to queue: spotify:track:3nojBsmTikUgDWOXbndv12 Sep 03 18:47:36 mr.thnh volumio[1098]: info: Exploding uri spotify:track:3nojBsmTikUgDWOXbndv12 in service spop Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: EXPLODING URI:spotify:track:3nojBsmTikUgDWOXbndv12 Sep 03 18:47:36 mr.thnh volumio[1098]: info: Adding Item to queue: spotify:track:4dMjHsWm4Nt2Gzw5j6KXM9 Sep 03 18:47:36 mr.thnh volumio[1098]: info: Exploding uri spotify:track:4dMjHsWm4Nt2Gzw5j6KXM9 in service spop Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: EXPLODING URI:spotify:track:4dMjHsWm4Nt2Gzw5j6KXM9 Sep 03 18:47:36 mr.thnh volumio[1098]: info: Adding Item to queue: spotify:track:3e8hAZfzqUx9RTq3uBL5nB Sep 03 18:47:36 mr.thnh volumio[1098]: info: Exploding uri spotify:track:3e8hAZfzqUx9RTq3uBL5nB in service spop Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: EXPLODING URI:spotify:track:3e8hAZfzqUx9RTq3uBL5nB Sep 03 18:47:36 mr.thnh volumio[1098]: info: Adding Item to queue: spotify:track:5Gp9vCbQFiCAYhjiVXXgmz Sep 03 18:47:36 mr.thnh volumio[1098]: info: Exploding uri spotify:track:5Gp9vCbQFiCAYhjiVXXgmz in service spop Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: EXPLODING URI:spotify:track:5Gp9vCbQFiCAYhjiVXXgmz Sep 03 18:47:36 mr.thnh volumio[1098]: info: Adding Item to queue: spotify:track:17DzRY10Qlk078arLL3isJ Sep 03 18:47:36 mr.thnh volumio[1098]: info: Exploding uri spotify:track:17DzRY10Qlk078arLL3isJ in service spop Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: EXPLODING URI:spotify:track:17DzRY10Qlk078arLL3isJ Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreStateMachine::stop Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreStateMachine::play index undefined Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreStateMachine::setConsumeUpdateService undefined Sep 03 18:47:36 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreStateMachine::startPlaybackTimer Sep 03 18:47:36 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioGetVisibleSources Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Sep 03 18:47:36 mr.thnh volumio[1098]: info: [1756900056073] ControllerSpotify::clearAddPlayTrack Sep 03 18:47:36 mr.thnh volumio[1098]: info: Sending Spotify command with payload to local API: /player/play Sep 03 18:47:36 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:36+07:00" level=debug msg="resolved context of track" uri="spotify:track:5OrpSDeWfWr33q0a5Ydfhr" Sep 03 18:47:36 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:36+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5OrpSDeWfWr33q0a5Ydfhr" Sep 03 18:47:36 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:36+07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5OrpSDeWfWr33q0a5Ydfhr" Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:4dMjHsWm4Nt2Gzw5j6KXM9","service":"spop","name":"Trái Tim Bên Lề","artist":"Bằng Kiều","album":"Chuyện Lạ (Vol. 1)","type":"song","duration":317,"albumart":"https://i.scdn.co/image/ab67616d0000b27350974aa454ba797fc178b410","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2qxeAIiuFJRpxQpJGVbHWP","service":"spop","name":"NÉT","artist":"Cường Seven","album":"Anh Trai Vượt Ngàn Chông Gai 2024 - Công Diễn 5","type":"song","duration":212,"albumart":"https://i.scdn.co/image/ab67616d0000b273580f99ff9ad3ae24eb073d88","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5JTZCDMaElB4ZBJc41YhMB","service":"spop","name":"Dẫu Có Lỗi Lầm","artist":"Bằng Kiều","album":"Anh Trai Vượt Ngàn Chông Gai 2024 - Công Diễn 2","type":"song","duration":314,"albumart":"https://i.scdn.co/image/ab67616d0000b273a1b00eff237847eb731c66ea","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5Gp9vCbQFiCAYhjiVXXgmz","service":"spop","name":"Đắp Mộ Cuộc Tình","artist":"Bằng Kiều","album":"Nhịp Cầu Tri Âm","type":"song","duration":353,"albumart":"https://i.scdn.co/image/ab67616d0000b273183ccaf786498504d5dd933a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3e8hAZfzqUx9RTq3uBL5nB","service":"spop","name":"Để Nhớ Một Thời Ta Đã Yêu","artist":"Bằng Kiều","album":"Một Lần Nữa Xin Có Nhau","type":"song","duration":315,"albumart":"https://i.scdn.co/image/ab67616d0000b273dbcca3a3c3b1a9f342cfbc79","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3nojBsmTikUgDWOXbndv12","service":"spop","name":"GENE x CÓ KHÔNG GIỮ MẤT ĐỪNG TÌM","artist":"Cường Seven","album":"Anh Trai Vượt Ngàn Chông Gai 2024 - Chung Kết","type":"song","duration":216,"albumart":"https://i.scdn.co/image/ab67616d0000b2737ffd0c4e33388522e19adaee","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:5ghwPzuXDM7mYScuNy5nZY","service":"spop","name":"Cơn Mơ Băng Giá","artist":"Bằng Kiều","album":"Cơn Mơ Băng Giá","type":"song","duration":280,"albumart":"https://i.scdn.co/image/ab67616d0000b2737d05c57a4a5bcf0d7c7e5d7a","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:6VHCSC1ofv6erC0rmvvPrj","service":"spop","name":"Hỏa Ca - Call Me By Fire","artist":"Bằng Kiều","album":"Hỏa Ca - Call Me By Fire","type":"song","duration":270,"albumart":"https://i.scdn.co/image/ab67616d0000b2737179d4c85eddfa7dd13df662","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 03 18:47:36 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:36+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 03 18:47:36 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:36+07:00" level=trace msg="emitting websocket event: will_play" Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5OrpSDeWfWr33q0a5Ydfhr","play_origin":"go-librespot"}} Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5OrpSDeWfWr33q0a5Ydfhr","play_origin":"go-librespot"}} Sep 03 18:47:36 mr.thnh volumio[1098]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:17DzRY10Qlk078arLL3isJ","service":"spop","name":"Bởi Vì Anh Yêu Em","artist":"Minh Tuyết","album":"Bởi Vì Anh Yêu Em","type":"song","duration":247,"albumart":"https://i.scdn.co/image/ab67616d0000b2731493e8679cb68ac1610f72d1","samplerate":"320 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushQueue Sep 03 18:47:36 mr.thnh volumio[1098]: info: CorePlayQueue::saveQueue Sep 03 18:47:36 mr.thnh volumio[1098]: info: CoreStateMachine::updateTrackBlock Sep 03 18:47:36 mr.thnh volumio[1098]: info: CorePlayQueue::getTrackBlock Sep 03 18:47:36 mr.thnh volumio[1098]: 0+0 records in Sep 03 18:47:36 mr.thnh volumio[1098]: 0+0 records out Sep 03 18:47:36 mr.thnh volumio[1098]: 0 bytes copied, 2.7582e-05 s, 0.0 kB/s Sep 03 18:47:36 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:36+07:00" level=debug msg="selected format OGG_VORBIS_320 (7f32eaf2a76cf4ec918226e97205a7c01b983bf4)" uri="spotify:track:5OrpSDeWfWr33q0a5Ydfhr" Sep 03 18:47:36 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:36+07:00" level=debug msg="requested aes key for file 7f32eaf2a76cf4ec918226e97205a7c01b983bf4, gid: 5OrpSDeWfWr33q0a5Ydfhr" Sep 03 18:47:36 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:36+07:00" level=trace msg="found 2 cdn urls" uri="spotify:track:5OrpSDeWfWr33q0a5Ydfhr" Sep 03 18:47:37 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:37+07:00" level=debug msg="fetched first chunk of 23, total size is 12018066 bytes" uri="spotify:track:5OrpSDeWfWr33q0a5Ydfhr" Sep 03 18:47:37 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:37+07: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" Sep 03 18:47:37 mr.thnh volumio[1098]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Sep 03 18:47:37 mr.thnh volumio[1098]: info: FusionDsp - ---- read samplerate from file: 44100 Sep 03 18:47:37 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:37+07:00" level=info msg="loaded track \"MẸ YÊU CON\" (paused: false, position: 0ms, duration: 305142ms, prefetched: false)" uri="spotify:track:5OrpSDeWfWr33q0a5Ydfhr" Sep 03 18:47:37 mr.thnh volumio[1098]: error: FusionDsp - File size not found in array! Sep 03 18:47:37 mr.thnh volumio[1098]: info: FusionDsp - Nulleq applied Sep 03 18:47:37 mr.thnh volumio[1098]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Sep 03 18:47:37 mr.thnh volumio[1098]: info: FusionDsp - ---- read samplerate from file: 44100 Sep 03 18:47:37 mr.thnh volumio[1098]: error: FusionDsp - File size not found in array! Sep 03 18:47:37 mr.thnh volumio[1098]: info: FusionDsp - Nulleq applied Sep 03 18:47:37 mr.thnh volumio[1098]: error: FusionDsp - Reload WebSocket error: [object Object] Sep 03 18:47:37 mr.thnh volumio[1098]: error: FusionDsp - Reload WebSocket error: [object Object] Sep 03 18:47:37 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:37 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:37 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:37 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 7.8612e-05 s, 834 MB/s Sep 03 18:47:37 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:37+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 03 18:47:37 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:37+07:00" level=trace msg="scheduling prefetch in 275s" Sep 03 18:47:37 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:37+07:00" level=trace msg="emitting websocket event: metadata" Sep 03 18:47:37 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5OrpSDeWfWr33q0a5Ydfhr","name":"MẸ YÊU CON","artist_names":["Cường Seven","Phan Đinh Tùng","Bằng Kiều","Jun Phạm","Tự Long","Trương Thế Vinh","Tuấn Hưng","SOOBIN","S.T Sơn Thạch","Kay Trần","BB Trần","(S)TRONG","Kiên Ứng"],"album_name":"Anh Trai Vượt Ngàn Chông Gai 2024 - Chung Kết","album_cover_url":"https://i.scdn.co/image/ab67616d00001e027ffd0c4e33388522e19adaee","position":0,"duration":305142,"release_date":"year:2024 month:10 day:19","track_number":3,"disc_number":1}} Sep 03 18:47:37 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5OrpSDeWfWr33q0a5Ydfhr","name":"MẸ YÊU CON","artist_names":["Cường Seven","Phan Đinh Tùng","Bằng Kiều","Jun Phạm","Tự Long","Trương Thế Vinh","Tuấn Hưng","SOOBIN","S.T Sơn Thạch","Kay Trần","BB Trần","(S)TRONG","Kiên Ứng"],"album_name":"Anh Trai Vượt Ngàn Chông Gai 2024 - Chung Kết","album_cover_url":"https://i.scdn.co/image/ab67616d00001e027ffd0c4e33388522e19adaee","position":0,"duration":305142,"release_date":"year:2024 month:10 day:19","track_number":3,"disc_number":1}} Sep 03 18:47:37 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:37+07:00" level=debug msg="fetched chunk 1/22, size: 524288" uri="spotify:track:5OrpSDeWfWr33q0a5Ydfhr" Sep 03 18:47:37 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:37+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Sep 03 18:47:37 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:37+07:00" level=trace msg="emitting websocket event: playing" Sep 03 18:47:37 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5OrpSDeWfWr33q0a5Ydfhr","resume":false,"play_origin":"go-librespot"}} Sep 03 18:47:37 mr.thnh volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Sep 03 18:47:37 mr.thnh volumio[1098]: SPOTIFY: {"status":"play","service":"spop","title":"MẸ YÊU CON","artist":"Cường Seven, Phan Đinh Tùng, Bằng Kiều, Jun Phạm, Tự Long, Trương Thế Vinh, Tuấn Hưng, SOOBIN, S.T Sơn Thạch, Kay Trần, BB Trần, (S)TRONG, Kiên Ứng","album":"Anh Trai Vượt Ngàn Chông Gai 2024 - Chung Kết","albumart":"https://i.scdn.co/image/ab67616d00001e027ffd0c4e33388522e19adaee","uri":"spotify:track:5OrpSDeWfWr33q0a5Ydfhr","trackType":"spotify","seek":0,"duration":305,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:37 mr.thnh volumio[1098]: info: CoreCommandRouter::servicePushState Sep 03 18:47:37 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:37 mr.thnh volumio[1098]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"MẸ YÊU CON","artist":"Cường Seven, Phan Đinh Tùng, Bằng Kiều, Jun Phạm, Tự Long, Trương Thế Vinh, Tuấn Hưng, SOOBIN, S.T Sơn Thạch, Kay Trần, BB Trần, (S)TRONG, Kiên Ứng","album":"Anh Trai Vượt Ngàn Chông Gai 2024 - Chung Kết","albumart":"https://i.scdn.co/image/ab67616d00001e027ffd0c4e33388522e19adaee","uri":"spotify:track:5OrpSDeWfWr33q0a5Ydfhr","trackType":"spotify","seek":0,"duration":305,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:37 mr.thnh volumio[1098]: verbose: CURRENT POSITION 0 Sep 03 18:47:37 mr.thnh volumio[1098]: info: CoreStateMachine::syncState stateService play Sep 03 18:47:37 mr.thnh volumio[1098]: info: CoreStateMachine::syncState currentStatus stop Sep 03 18:47:37 mr.thnh volumio[1098]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5OrpSDeWfWr33q0a5Ydfhr","resume":false,"play_origin":"go-librespot"}} Sep 03 18:47:37 mr.thnh volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Sep 03 18:47:37 mr.thnh volumio[1098]: SPOTIFY: {"status":"play","service":"spop","title":"MẸ YÊU CON","artist":"Cường Seven, Phan Đinh Tùng, Bằng Kiều, Jun Phạm, Tự Long, Trương Thế Vinh, Tuấn Hưng, SOOBIN, S.T Sơn Thạch, Kay Trần, BB Trần, (S)TRONG, Kiên Ứng","album":"Anh Trai Vượt Ngàn Chông Gai 2024 - Chung Kết","albumart":"https://i.scdn.co/image/ab67616d00001e027ffd0c4e33388522e19adaee","uri":"spotify:track:5OrpSDeWfWr33q0a5Ydfhr","trackType":"spotify","seek":0,"duration":305,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:37 mr.thnh volumio[1098]: info: CoreCommandRouter::servicePushState Sep 03 18:47:37 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:37 mr.thnh volumio[1098]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"MẸ YÊU CON","artist":"Cường Seven, Phan Đinh Tùng, Bằng Kiều, Jun Phạm, Tự Long, Trương Thế Vinh, Tuấn Hưng, SOOBIN, S.T Sơn Thạch, Kay Trần, BB Trần, (S)TRONG, Kiên Ứng","album":"Anh Trai Vượt Ngàn Chông Gai 2024 - Chung Kết","albumart":"https://i.scdn.co/image/ab67616d00001e027ffd0c4e33388522e19adaee","uri":"spotify:track:5OrpSDeWfWr33q0a5Ydfhr","trackType":"spotify","seek":0,"duration":305,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:37 mr.thnh volumio[1098]: verbose: CURRENT POSITION 0 Sep 03 18:47:37 mr.thnh volumio[1098]: info: CoreStateMachine::syncState stateService play Sep 03 18:47:37 mr.thnh volumio[1098]: info: CoreStateMachine::syncState currentStatus play Sep 03 18:47:37 mr.thnh volumio[1098]: info: Received an update from plugin. extracting info from payload Sep 03 18:47:37 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:37 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:37 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Sep 03 18:47:37 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:37 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:37 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:37 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:37 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:37 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:37 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:37 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:37 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:37 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:37 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:37 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:37 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:47:37 mr.thnh volumio[1098]: warn: FusionDsp - Monitor WebSocket not open, skipping commands Sep 03 18:47:37 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:47:37 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:37 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:38 mr.thnh volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Sep 03 18:47:38 mr.thnh volumio[1098]: SPOTIFY: {"status":"play","service":"spop","title":"MẸ YÊU CON","artist":"Cường Seven, Phan Đinh Tùng, Bằng Kiều, Jun Phạm, Tự Long, Trương Thế Vinh, Tuấn Hưng, SOOBIN, S.T Sơn Thạch, Kay Trần, BB Trần, (S)TRONG, Kiên Ứng","album":"Anh Trai Vượt Ngàn Chông Gai 2024 - Chung Kết","albumart":"https://i.scdn.co/image/ab67616d00001e027ffd0c4e33388522e19adaee","uri":"spotify:track:5OrpSDeWfWr33q0a5Ydfhr","trackType":"spotify","seek":0,"duration":305,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:38 mr.thnh volumio[1098]: info: CoreCommandRouter::servicePushState Sep 03 18:47:38 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:38 mr.thnh volumio[1098]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"MẸ YÊU CON","artist":"Cường Seven, Phan Đinh Tùng, Bằng Kiều, Jun Phạm, Tự Long, Trương Thế Vinh, Tuấn Hưng, SOOBIN, S.T Sơn Thạch, Kay Trần, BB Trần, (S)TRONG, Kiên Ứng","album":"Anh Trai Vượt Ngàn Chông Gai 2024 - Chung Kết","albumart":"https://i.scdn.co/image/ab67616d00001e027ffd0c4e33388522e19adaee","uri":"spotify:track:5OrpSDeWfWr33q0a5Ydfhr","trackType":"spotify","seek":0,"duration":305,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:38 mr.thnh volumio[1098]: verbose: CURRENT POSITION 0 Sep 03 18:47:38 mr.thnh volumio[1098]: info: CoreStateMachine::syncState stateService play Sep 03 18:47:38 mr.thnh volumio[1098]: info: CoreStateMachine::syncState currentStatus play Sep 03 18:47:38 mr.thnh volumio[1098]: info: Received an update from plugin. extracting info from payload Sep 03 18:47:38 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:38 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:38 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:38 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:38 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:38 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:38 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:38 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:38 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:38 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:38 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:38 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:38 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:38 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:38 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:47:38 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:47:38 mr.thnh volumio[1098]: SPOTIFY: PUSH STATE SPOTIFY Sep 03 18:47:38 mr.thnh volumio[1098]: SPOTIFY: {"status":"play","service":"spop","title":"MẸ YÊU CON","artist":"Cường Seven, Phan Đinh Tùng, Bằng Kiều, Jun Phạm, Tự Long, Trương Thế Vinh, Tuấn Hưng, SOOBIN, S.T Sơn Thạch, Kay Trần, BB Trần, (S)TRONG, Kiên Ứng","album":"Anh Trai Vượt Ngàn Chông Gai 2024 - Chung Kết","albumart":"https://i.scdn.co/image/ab67616d00001e027ffd0c4e33388522e19adaee","uri":"spotify:track:5OrpSDeWfWr33q0a5Ydfhr","trackType":"spotify","seek":0,"duration":305,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:38 mr.thnh volumio[1098]: info: CoreCommandRouter::servicePushState Sep 03 18:47:38 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:38 mr.thnh volumio[1098]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"MẸ YÊU CON","artist":"Cường Seven, Phan Đinh Tùng, Bằng Kiều, Jun Phạm, Tự Long, Trương Thế Vinh, Tuấn Hưng, SOOBIN, S.T Sơn Thạch, Kay Trần, BB Trần, (S)TRONG, Kiên Ứng","album":"Anh Trai Vượt Ngàn Chông Gai 2024 - Chung Kết","albumart":"https://i.scdn.co/image/ab67616d00001e027ffd0c4e33388522e19adaee","uri":"spotify:track:5OrpSDeWfWr33q0a5Ydfhr","trackType":"spotify","seek":0,"duration":305,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Sep 03 18:47:38 mr.thnh volumio[1098]: verbose: CURRENT POSITION 0 Sep 03 18:47:38 mr.thnh volumio[1098]: info: CoreStateMachine::syncState stateService play Sep 03 18:47:38 mr.thnh volumio[1098]: info: CoreStateMachine::syncState currentStatus play Sep 03 18:47:38 mr.thnh volumio[1098]: info: Received an update from plugin. extracting info from payload Sep 03 18:47:38 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:38 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:38 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:38 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:38 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:38 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:38 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:38 mr.thnh volumio[1098]: info: CoreStateMachine::pushState Sep 03 18:47:38 mr.thnh volumio[1098]: info: CorePlayQueue::getTrack 0 Sep 03 18:47:38 mr.thnh volumio[1098]: info: CoreCommandRouter::volumioPushState Sep 03 18:47:38 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output update for this device Sep 03 18:47:38 mr.thnh volumio[1098]: info: MRS: Pushing multiroomSync output Sep 03 18:47:38 mr.thnh volumio[1098]: error: Help! Some callbacks for volumioPushState are crashing! Sep 03 18:47:38 mr.thnh volumio[1098]: error: Cannot read properties of undefined (reading 'sendVolumeMute') Sep 03 18:47:38 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:47:38 mr.thnh volumio[1098]: info: FusionDsp - Volumio is playing Sep 03 18:47:38 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:38 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:38 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:38 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:38 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:38 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:38 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:38 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 7.6564e-05 s, 856 MB/s Sep 03 18:47:39 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:39+07:00" level=debug msg="fetched chunk 3/22, size: 524288" uri="spotify:track:5OrpSDeWfWr33q0a5Ydfhr" Sep 03 18:47:39 mr.thnh go-librespot[5345]: time="2025-09-03T18:47:39+07:00" level=debug msg="fetched chunk 2/22, size: 524288" uri="spotify:track:5OrpSDeWfWr33q0a5Ydfhr" Sep 03 18:47:39 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:39 mr.thnh volumio[1098]: 1+1 records in Sep 03 18:47:39 mr.thnh volumio[1098]: 1+1 records out Sep 03 18:47:39 mr.thnh volumio[1098]: 61712 bytes (62 kB, 60 KiB) copied, 8.5922e-05 s, 718 MB/s Sep 03 18:47:39 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:47:39 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:47:39 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:47:39 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:47:39 mr.thnh volumio[1098]: info: Executing endpoint metavolumio Sep 03 18:47:39 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Sep 03 18:47:39 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:39 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:40 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:40 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:40 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:40 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:40 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:40 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:40 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:40 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 8.2692e-05 s, 793 MB/s Sep 03 18:47:41 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:41 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:41 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:41 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 7.6521e-05 s, 856 MB/s Sep 03 18:47:41 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:41 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:42 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:42 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:42 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:42 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:42 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:42 mr.thnh volumio[1098]: 1+1 records in Sep 03 18:47:42 mr.thnh volumio[1098]: 1+1 records out Sep 03 18:47:42 mr.thnh volumio[1098]: 61712 bytes (62 kB, 60 KiB) copied, 9.7102e-05 s, 636 MB/s Sep 03 18:47:43 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:43 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:43 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:43 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 9.0664e-05 s, 723 MB/s Sep 03 18:47:43 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:43 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:44 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:44 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:44 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:44 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:44 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:44 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:44 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:44 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 7.591e-05 s, 863 MB/s Sep 03 18:47:45 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:45 mr.thnh volumio[1098]: 1+1 records in Sep 03 18:47:45 mr.thnh volumio[1098]: 1+1 records out Sep 03 18:47:45 mr.thnh volumio[1098]: 61712 bytes (62 kB, 60 KiB) copied, 8.7404e-05 s, 706 MB/s Sep 03 18:47:45 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:45 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:46 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:46 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:46 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:46 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:46 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:46 mr.thnh volumio[1098]: 2+0 records in Sep 03 18:47:46 mr.thnh volumio[1098]: 2+0 records out Sep 03 18:47:46 mr.thnh volumio[1098]: 65536 bytes (66 kB, 64 KiB) copied, 8.303e-05 s, 789 MB/s Sep 03 18:47:47 mr.thnh volumio[1098]: Searching all installed plugins Sep 03 18:47:47 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Sep 03 18:47:47 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: , search Sep 03 18:47:47 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: mpd , search Sep 03 18:47:47 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Sep 03 18:47:47 mr.thnh volumio[1098]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Sep 03 18:47:47 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: webradio , search Sep 03 18:47:47 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: youtube2 , search Sep 03 18:47:47 mr.thnh volumio[1098]: info: [youtube2] InnertubeLoader: creating Innertube instance... Sep 03 18:47:47 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: ytmusic , search Sep 03 18:47:47 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: 80s80s , search Sep 03 18:47:47 mr.thnh volumio[1098]: info: CoreCommandRouter::executeOnPlugin: spop , search Sep 03 18:47:47 mr.thnh volumio[1098]: /bin/dd: error reading '/tmp/fusiondspfifo': Resource temporarily unavailable Sep 03 18:47:47 mr.thnh volumio[1098]: 1+1 records in Sep 03 18:47:47 mr.thnh volumio[1098]: 1+1 records out Sep 03 18:47:47 mr.thnh volumio[1098]: 61712 bytes (62 kB, 60 KiB) copied, 9.4186e-05 s, 655 MB/s Sep 03 18:47:47 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:47 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:48 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:48 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:48 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:48 mr.thnh volumio[1098]: error: FusionDsp - Monitor WebSocket error: [object Object] Sep 03 18:47:48 mr.thnh volumio[1098]: Use XMLElement.setAttribute instead Sep 03 18:47:48 mr.thnh volumio[1098]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 03 18:47:48 mr.thnh volumio[1098]: TypeError: children[i].attr(...).value is not a function Sep 03 18:47:48 mr.thnh volumio[1098]: at /volumio/app/plugins/music_service/webradio/index.js:956:46 Sep 03 18:47:48 mr.thnh volumio[1098]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) Sep 03 18:47:48 mr.thnh volumio[1098]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Sep 03 18:47:48 mr.thnh sudo[6402]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-09-03 18:46' Sep 03 18:47:48 mr.thnh sudo[6402]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Debian GNU/Linux 12 (bookworm)" NAME="Debian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="4a70cb031e64a8e498efc3e29470650871ff7d54" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat May 31 04:47:19 UTC 2025" VOLUMIO_VERSION="4.005" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="f0f6a90610a0a39b2758a5b3958219e6"