Dec 27 17:47:07 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:07 office volumio[13106]: info: Listing playlists Dec 27 17:47:07 office volumio[13106]: info: Listing playlists Dec 27 17:47:17 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:27 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:27 office volumio[13106]: info: Listing playlists Dec 27 17:47:27 office volumio[13106]: info: Listing playlists Dec 27 17:47:35 office sshd[14027]: Accepted password for volumio from 192.168.86.63 port 58174 ssh2 Dec 27 17:47:35 office sshd[14027]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0) Dec 27 17:47:35 office systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. Dec 27 17:47:35 office systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... Dec 27 17:47:35 office systemd-logind[676]: New session 43 of user volumio. Dec 27 17:47:35 office systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. Dec 27 17:47:35 office systemd[1]: Starting user@1000.service - User Manager for UID 1000... Dec 27 17:47:35 office (systemd)[14044]: pam_unix(systemd-user:session): session opened for user volumio(uid=1000) by (uid=0) Dec 27 17:47:36 office systemd[14044]: Queued start job for default target default.target. Dec 27 17:47:36 office systemd[14044]: Created slice app.slice - User Application Slice. Dec 27 17:47:36 office systemd[14044]: Reached target paths.target - Paths. Dec 27 17:47:36 office systemd[14044]: Reached target timers.target - Timers. Dec 27 17:47:36 office systemd[14044]: Listening on dirmngr.socket - GnuPG network certificate management daemon. Dec 27 17:47:36 office systemd[14044]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Dec 27 17:47:36 office systemd[14044]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Dec 27 17:47:36 office systemd[14044]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Dec 27 17:47:36 office systemd[14044]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Dec 27 17:47:36 office systemd[14044]: Reached target sockets.target - Sockets. Dec 27 17:47:36 office systemd[14044]: Reached target basic.target - Basic System. Dec 27 17:47:36 office systemd[1]: Started user@1000.service - User Manager for UID 1000. Dec 27 17:47:36 office systemd[14044]: Started mpris-proxy.service - Bluetooth mpris proxy. Dec 27 17:47:36 office systemd[14044]: Reached target default.target - Main User Target. Dec 27 17:47:36 office systemd[14044]: Startup finished in 396ms. Dec 27 17:47:36 office systemd[1]: Started session-43.scope - Session 43 of User volumio. Dec 27 17:47:36 office mpris-proxy[14059]: Can't get on session bus Dec 27 17:47:36 office systemd[14044]: mpris-proxy.service: Main process exited, code=exited, status=1/FAILURE Dec 27 17:47:36 office systemd[14044]: mpris-proxy.service: Failed with result 'exit-code'. Dec 27 17:47:36 office sshd[14027]: pam_env(sshd:session): deprecated reading of user environment enabled Dec 27 17:47:37 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:37 office sudo[14077]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/journalctl -f Dec 27 17:47:37 office sudo[14077]: pam_unix(sudo:session): session opened for user root(uid=0) by volumio(uid=1000) Dec 27 17:47:47 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:47 office volumio[13106]: info: Listing playlists Dec 27 17:47:47 office volumio[13106]: info: Listing playlists Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] <<< server/state: has_metadata=true, has_controller=false Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] <<< server/state metadata payload: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564359512, Dec 27 17:47:50 office volumio[13106]: "title": null, Dec 27 17:47:50 office volumio[13106]: "artist": null, Dec 27 17:47:50 office volumio[13106]: "album": null, Dec 27 17:47:50 office volumio[13106]: "artwork_url": null, Dec 27 17:47:50 office volumio[13106]: "repeat": null, Dec 27 17:47:50 office volumio[13106]: "shuffle": null Dec 27 17:47:50 office volumio[13106]: } Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] handleMetadata called with: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564359512, Dec 27 17:47:50 office volumio[13106]: "title": null, Dec 27 17:47:50 office volumio[13106]: "artist": null, Dec 27 17:47:50 office volumio[13106]: "album": null, Dec 27 17:47:50 office volumio[13106]: "artwork_url": null, Dec 27 17:47:50 office volumio[13106]: "repeat": null, Dec 27 17:47:50 office volumio[13106]: "shuffle": null Dec 27 17:47:50 office volumio[13106]: } Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] Metadata fields: title=null/undefined, artist=null/undefined, album=null/undefined, artwork_url=null/undefined/empty Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] Processed metadata object: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564359512, Dec 27 17:47:50 office volumio[13106]: "title": "King of NY", Dec 27 17:47:50 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:50 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:50 office volumio[13106]: "progress": { Dec 27 17:47:50 office volumio[13106]: "trackProgress": 379786, Dec 27 17:47:50 office volumio[13106]: "trackDuration": 233000 Dec 27 17:47:50 office volumio[13106]: }, Dec 27 17:47:50 office volumio[13106]: "repeat": "off", Dec 27 17:47:50 office volumio[13106]: "shuffle": false Dec 27 17:47:50 office volumio[13106]: } Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] onMetadata callback exists: true Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] Calling onMetadata callback with processed metadata Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] onMetadata callback received: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564359512, Dec 27 17:47:50 office volumio[13106]: "title": "King of NY", Dec 27 17:47:50 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:50 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:50 office volumio[13106]: "progress": { Dec 27 17:47:50 office volumio[13106]: "trackProgress": 379786, Dec 27 17:47:50 office volumio[13106]: "trackDuration": 233000 Dec 27 17:47:50 office volumio[13106]: }, Dec 27 17:47:50 office volumio[13106]: "repeat": "off", Dec 27 17:47:50 office volumio[13106]: "shuffle": false Dec 27 17:47:50 office volumio[13106]: } Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] Metadata check: hasTitle=true, hasArtist=true, title="King of NY", artist="Dan the Automator" Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] Metadata: Dan the Automator - King of NY (A Much Better Tomorrow) Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] Calling updateNowPlaying with metadata Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] updateNowPlaying called with metadata: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564359512, Dec 27 17:47:50 office volumio[13106]: "title": "King of NY", Dec 27 17:47:50 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:50 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:50 office volumio[13106]: "progress": { Dec 27 17:47:50 office volumio[13106]: "trackProgress": 379786, Dec 27 17:47:50 office volumio[13106]: "trackDuration": 233000 Dec 27 17:47:50 office volumio[13106]: }, Dec 27 17:47:50 office volumio[13106]: "repeat": "off", Dec 27 17:47:50 office volumio[13106]: "shuffle": false Dec 27 17:47:50 office volumio[13106]: }, retryCount=0 Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] updateNowPlaying called with metadata: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564359512, Dec 27 17:47:50 office volumio[13106]: "title": "King of NY", Dec 27 17:47:50 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:50 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:50 office volumio[13106]: "progress": { Dec 27 17:47:50 office volumio[13106]: "trackProgress": 379786, Dec 27 17:47:50 office volumio[13106]: "trackDuration": 233000 Dec 27 17:47:50 office volumio[13106]: }, Dec 27 17:47:50 office volumio[13106]: "repeat": "off", Dec 27 17:47:50 office volumio[13106]: "shuffle": false Dec 27 17:47:50 office volumio[13106]: }, retryCount=0 Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] onMetadata callback completed successfully Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] <<< server/state: has_metadata=true, has_controller=false Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] <<< server/state metadata payload: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564401402, Dec 27 17:47:50 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:50 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artwork_url": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:50 office volumio[13106]: "progress": { Dec 27 17:47:50 office volumio[13106]: "track_progress": 611339, Dec 27 17:47:50 office volumio[13106]: "track_duration": 357000, Dec 27 17:47:50 office volumio[13106]: "playback_speed": 1000 Dec 27 17:47:50 office volumio[13106]: }, Dec 27 17:47:50 office volumio[13106]: "repeat": "off", Dec 27 17:47:50 office volumio[13106]: "shuffle": false Dec 27 17:47:50 office volumio[13106]: } Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] handleMetadata called with: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564401402, Dec 27 17:47:50 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:50 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artwork_url": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:50 office volumio[13106]: "progress": { Dec 27 17:47:50 office volumio[13106]: "track_progress": 611339, Dec 27 17:47:50 office volumio[13106]: "track_duration": 357000, Dec 27 17:47:50 office volumio[13106]: "playback_speed": 1000 Dec 27 17:47:50 office volumio[13106]: }, Dec 27 17:47:50 office volumio[13106]: "repeat": "off", Dec 27 17:47:50 office volumio[13106]: "shuffle": false Dec 27 17:47:50 office volumio[13106]: } Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] Metadata fields: title="A Better Tomorrow", artist="Dan the Automator", album=A Much Better Tomorrow, artwork_url="http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png" Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] Processed metadata object: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564401402, Dec 27 17:47:50 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:50 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:50 office volumio[13106]: "progress": { Dec 27 17:47:50 office volumio[13106]: "trackProgress": 611339, Dec 27 17:47:50 office volumio[13106]: "trackDuration": 357000 Dec 27 17:47:50 office volumio[13106]: }, Dec 27 17:47:50 office volumio[13106]: "repeat": "off", Dec 27 17:47:50 office volumio[13106]: "shuffle": false Dec 27 17:47:50 office volumio[13106]: } Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] onMetadata callback exists: true Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] Calling onMetadata callback with processed metadata Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] onMetadata callback received: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564401402, Dec 27 17:47:50 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:50 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:50 office volumio[13106]: "progress": { Dec 27 17:47:50 office volumio[13106]: "trackProgress": 611339, Dec 27 17:47:50 office volumio[13106]: "trackDuration": 357000 Dec 27 17:47:50 office volumio[13106]: }, Dec 27 17:47:50 office volumio[13106]: "repeat": "off", Dec 27 17:47:50 office volumio[13106]: "shuffle": false Dec 27 17:47:50 office volumio[13106]: } Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] Metadata check: hasTitle=true, hasArtist=true, title="A Better Tomorrow", artist="Dan the Automator" Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] Metadata: Dan the Automator - A Better Tomorrow (A Much Better Tomorrow) Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] Calling updateNowPlaying with metadata Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] updateNowPlaying called with metadata: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564401402, Dec 27 17:47:50 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:50 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:50 office volumio[13106]: "progress": { Dec 27 17:47:50 office volumio[13106]: "trackProgress": 611339, Dec 27 17:47:50 office volumio[13106]: "trackDuration": 357000 Dec 27 17:47:50 office volumio[13106]: }, Dec 27 17:47:50 office volumio[13106]: "repeat": "off", Dec 27 17:47:50 office volumio[13106]: "shuffle": false Dec 27 17:47:50 office volumio[13106]: }, retryCount=0 Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] updateNowPlaying: Valid artwork URL: "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png" Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] updateNowPlaying: title="A Better Tomorrow", artist="Dan the Automator", album="A Much Better Tomorrow", artworkUrl="http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png" Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] updateNowPlaying: streamUrl=null, stateMachine=true, playQueue=true Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] updateNowPlaying: Checking queue at position 0, queue length=1 Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] updateNowPlaying: Track at position 0: uri=http://127.0.0.1:45227/stream, service=sendspin Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] updateNowPlaying: Searching entire queue for streamUrl=null Dec 27 17:47:50 office volumio[13106]: warn: [Sendspin] Could not find current track in queue (uri=null, found=http://127.0.0.1:45227/stream, queue length=1) Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] Queue[0]: uri=http://127.0.0.1:45227/stream, service=sendspin, title=none Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] updateNowPlaying: Sending state update to Volumio: { Dec 27 17:47:50 office volumio[13106]: "service": "sendspin", Dec 27 17:47:50 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:50 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "albumart": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%...", Dec 27 17:47:50 office volumio[13106]: "uri": null, Dec 27 17:47:50 office volumio[13106]: "type": "webradio", Dec 27 17:47:50 office volumio[13106]: "trackType": "sendspin", Dec 27 17:47:50 office volumio[13106]: "status": "stop", Dec 27 17:47:50 office volumio[13106]: "position": 611339, Dec 27 17:47:50 office volumio[13106]: "duration": 357000, Dec 27 17:47:50 office volumio[13106]: "samplerate": "", Dec 27 17:47:50 office volumio[13106]: "bitdepth": "", Dec 27 17:47:50 office volumio[13106]: "channels": "", Dec 27 17:47:50 office volumio[13106]: "volume": 100, Dec 27 17:47:50 office volumio[13106]: "mute": false Dec 27 17:47:50 office volumio[13106]: } Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:50 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:50 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:50 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:50 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:50 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":null,"type":"webradio","trackType":"sendspin","status":"stop","position":611339,"duration":357000,"samplerate":"","bitdepth":"","channels":"","volume":100,"mute":false} Dec 27 17:47:50 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:50 office volumio[13106]: info: CoreStateMachine::syncState stateService stop Dec 27 17:47:50 office volumio[13106]: info: CoreStateMachine::syncState currentStatus stop Dec 27 17:47:50 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:50 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:50 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:50 office volumio[13106]: info: No code Dec 27 17:47:50 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:50 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:50 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] Called servicePushState('sendspin') with: Dan the Automator - A Better Tomorrow (artwork: http://192.168.86.37:8095/imageproxy?provider=file...) Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] updateNowPlaying called with metadata: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564401402, Dec 27 17:47:50 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:50 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:50 office volumio[13106]: "progress": { Dec 27 17:47:50 office volumio[13106]: "trackProgress": 611339, Dec 27 17:47:50 office volumio[13106]: "trackDuration": 357000 Dec 27 17:47:50 office volumio[13106]: }, Dec 27 17:47:50 office volumio[13106]: "repeat": "off", Dec 27 17:47:50 office volumio[13106]: "shuffle": false Dec 27 17:47:50 office volumio[13106]: }, retryCount=0 Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] onMetadata callback completed successfully Dec 27 17:47:50 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.status' Dec 27 17:47:50 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.status' Dec 27 17:47:50 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.status' Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] Stream start received Dec 27 17:47:50 office volumio[13106]: info: [AudioScheduler] Started scheduler (buffer target: 550 chunks) Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] Stream started: opus 48000Hz Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] Initializing decoder with format: opus 48000Hz 2ch Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] <<< BINARY #1: type=8, timestamp=812564621214μs, serverNow=812564742428μs, diff=-121214μs (-121.2ms), size=55266 bytes, audio=55257 bytes, sync=good Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] group/update: playback_state=playing Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] Playback state changed: stopped -> playing Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] Playback state changed: playing Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] Resuming Volumio playback Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::volumioPlay Dec 27 17:47:50 office volumio[13106]: verbose: UNSET VOLATILE: Service: undefined Dec 27 17:47:50 office volumio[13106]: ------------------------------------ BT MESSAGE: [FUNC] detachBluetooth Dec 27 17:47:50 office volumio[13106]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput Dec 27 17:47:50 office volumio[13106]: ------------------------------------ BT MESSAGE: [dbus-next] Disabling Bluetooth Audio Output Dec 27 17:47:50 office volumio[13106]: info: CoreStateMachine::play index undefined Dec 27 17:47:50 office volumio[13106]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] updateNowPlaying called with metadata: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564401402, Dec 27 17:47:50 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:50 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:50 office volumio[13106]: "progress": { Dec 27 17:47:50 office volumio[13106]: "trackProgress": 611339, Dec 27 17:47:50 office volumio[13106]: "trackDuration": 357000 Dec 27 17:47:50 office volumio[13106]: }, Dec 27 17:47:50 office volumio[13106]: "repeat": "off", Dec 27 17:47:50 office volumio[13106]: "shuffle": false Dec 27 17:47:50 office volumio[13106]: }, retryCount=0 Dec 27 17:47:50 office volumio[13106]: ------------------------------------ BT MESSAGE: Bluetooth audio output disabled. Dec 27 17:47:50 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:50 office volumio[13106]: info: CoreStateMachine::startPlaybackTimer Dec 27 17:47:50 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::volumioGetVisibleSources Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 27 17:47:50 office volumio[13106]: info: CoreStateMachine::resetVolumioState Dec 27 17:47:50 office volumio[13106]: info: CoreStateMachine::getcurrentVolume Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::volumioRetrievevolume Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::volumioStop Dec 27 17:47:50 office volumio[13106]: info: CoreStateMachine::stop Dec 27 17:47:50 office volumio[13106]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 17:47:50 office volumio[13106]: info: [AudioDecoder] Using WASM Opus decoder (opus-decoder). Decoder type: object, has decode: undefined, sampleRate: 48000, channels: 2 Dec 27 17:47:50 office volumio[13106]: info: [AudioDecoder] Using WASM Opus decoder (opus-decoder). Decoder type: object, has decode: undefined, sampleRate: 48000, channels: 2 Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] Decoder initialized successfully. isInitialized: true, has decoder: true Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:50 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:50 office volumio[13106]: info: [AudioPlayer] Current Volumio state: volume=0, mute=false Dec 27 17:47:50 office volumio[13106]: warn: [AudioPlayer] Volume is 0! Setting to 50%... Dec 27 17:47:50 office volumio[13106]: info: [AudioPlayer] HTTP stream server listening on http://127.0.0.1:37539/stream Dec 27 17:47:50 office volumio[13106]: info: [AudioPlayer] Stream server created, setting isPlaying=true Dec 27 17:47:50 office volumio[13106]: info: [AudioPlayer] addToMPDQueue called: commandRouter=true, streamUrl=http://127.0.0.1:37539/stream Dec 27 17:47:50 office volumio[13106]: info: [AudioPlayer] Attempting to add stream to Volumio queue and MPD: http://127.0.0.1:37539/stream Dec 27 17:47:50 office volumio[13106]: info: [AudioPlayer] Track metadata: {"uri":"http://127.0.0.1:37539/stream","service":"sendspin","name":"Sendspin Stream","title":"Sendspin Stream","artist":"Sendspin","album":"Live Stream","type":"webradio","trackType":"sendspin","duration":1} Dec 27 17:47:50 office volumio[13106]: info: [AudioPlayer] Available methods: executeOnPlugin=true, replaceAndPlay=true, addQueueItems=true Dec 27 17:47:50 office volumio[13106]: info: [AudioPlayer] Adding track to Volumio play queue first... Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::volumioAddQueueItems Dec 27 17:47:50 office volumio[13106]: info: CoreStateMachine::addQueueItems Dec 27 17:47:50 office volumio[13106]: info: CorePlayQueue::addQueueItems Dec 27 17:47:50 office volumio[13106]: info: Preload queue cleared Dec 27 17:47:50 office volumio[13106]: info: Adding Item to queue: http://127.0.0.1:37539/stream Dec 27 17:47:50 office volumio[13106]: info: Exploding uri http://127.0.0.1:37539/stream in service sendspin Dec 27 17:47:50 office volumio[13106]: info: [AudioPlayer] Started playback via MPD on http://127.0.0.1:37539/stream (isPlaying=true, startPaused=false) Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] Audio playback started Dec 27 17:47:50 office volumio[13106]: info: [Sendspin] updateNowPlaying called with metadata: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564401402, Dec 27 17:47:50 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:50 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:50 office volumio[13106]: "progress": { Dec 27 17:47:50 office volumio[13106]: "trackProgress": 611339, Dec 27 17:47:50 office volumio[13106]: "trackDuration": 357000 Dec 27 17:47:50 office volumio[13106]: }, Dec 27 17:47:50 office volumio[13106]: "repeat": "off", Dec 27 17:47:50 office volumio[13106]: "shuffle": false Dec 27 17:47:50 office volumio[13106]: }, retryCount=0 Dec 27 17:47:50 office volumio[13106]: info: CoreCommandRouter::volumioPushQueue Dec 27 17:47:50 office volumio[13106]: info: CorePlayQueue::saveQueue Dec 27 17:47:50 office volumio[13106]: info: CoreStateMachine::updateTrackBlock Dec 27 17:47:50 office volumio[13106]: info: CorePlayQueue::getTrackBlock Dec 27 17:47:50 office volumio[13106]: info: [AudioPlayer] Added track to Volumio play queue Dec 27 17:47:50 office volumio[13106]: verbose: ControllerMpd::sendMpdCommand stop Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] <<< server/state: has_metadata=true, has_controller=false Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] <<< server/state metadata payload: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564645345, Dec 27 17:47:50 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:50 office volumio[13106]: "album_artist": null, Dec 27 17:47:50 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artwork_url": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:50 office volumio[13106]: "year": null, Dec 27 17:47:50 office volumio[13106]: "track": null, Dec 27 17:47:50 office volumio[13106]: "progress": { Dec 27 17:47:50 office volumio[13106]: "track_progress": 357000, Dec 27 17:47:50 office volumio[13106]: "track_duration": 357000, Dec 27 17:47:50 office volumio[13106]: "playback_speed": 1000 Dec 27 17:47:50 office volumio[13106]: }, Dec 27 17:47:50 office volumio[13106]: "repeat": "off", Dec 27 17:47:50 office volumio[13106]: "shuffle": false Dec 27 17:47:50 office volumio[13106]: } Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] handleMetadata called with: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564645345, Dec 27 17:47:50 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:50 office volumio[13106]: "album_artist": null, Dec 27 17:47:50 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artwork_url": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:50 office volumio[13106]: "year": null, Dec 27 17:47:50 office volumio[13106]: "track": null, Dec 27 17:47:50 office volumio[13106]: "progress": { Dec 27 17:47:50 office volumio[13106]: "track_progress": 357000, Dec 27 17:47:50 office volumio[13106]: "track_duration": 357000, Dec 27 17:47:50 office volumio[13106]: "playback_speed": 1000 Dec 27 17:47:50 office volumio[13106]: }, Dec 27 17:47:50 office volumio[13106]: "repeat": "off", Dec 27 17:47:50 office volumio[13106]: "shuffle": false Dec 27 17:47:50 office volumio[13106]: } Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] Metadata fields: title="A Better Tomorrow", artist="Dan the Automator", album=A Much Better Tomorrow, artwork_url="http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png" Dec 27 17:47:50 office volumio[13106]: info: [SendspinClient] Processed metadata object: { Dec 27 17:47:50 office volumio[13106]: "timestamp": 812564645345, Dec 27 17:47:50 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:50 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:50 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:50 office volumio[13106]: "progress": { Dec 27 17:47:50 office volumio[13106]: "trackProgress": 357000, Dec 27 17:47:50 office volumio[13106]: "trackDuration": 357000 Dec 27 17:47:50 office volumio[13106]: }, Dec 27 17:47:50 office volumio[13106]: "repeat": "off", Dec 27 17:47:50 office volumio[13106]: "shuffle": false Dec 27 17:47:50 office volumio[13106]: } Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] onMetadata callback exists: true Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Calling onMetadata callback with processed metadata Dec 27 17:47:51 office volumio[13106]: info: [Sendspin] onMetadata callback received: { Dec 27 17:47:51 office volumio[13106]: "timestamp": 812564645345, Dec 27 17:47:51 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:51 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:51 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:51 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:51 office volumio[13106]: "progress": { Dec 27 17:47:51 office volumio[13106]: "trackProgress": 357000, Dec 27 17:47:51 office volumio[13106]: "trackDuration": 357000 Dec 27 17:47:51 office volumio[13106]: }, Dec 27 17:47:51 office volumio[13106]: "repeat": "off", Dec 27 17:47:51 office volumio[13106]: "shuffle": false Dec 27 17:47:51 office volumio[13106]: } Dec 27 17:47:51 office volumio[13106]: info: [Sendspin] Metadata check: hasTitle=true, hasArtist=true, title="A Better Tomorrow", artist="Dan the Automator" Dec 27 17:47:51 office volumio[13106]: info: [Sendspin] Metadata: Dan the Automator - A Better Tomorrow (A Much Better Tomorrow) Dec 27 17:47:51 office volumio[13106]: info: [Sendspin] Calling updateNowPlaying with metadata Dec 27 17:47:51 office volumio[13106]: info: [Sendspin] updateNowPlaying called with metadata: { Dec 27 17:47:51 office volumio[13106]: "timestamp": 812564645345, Dec 27 17:47:51 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:51 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:51 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:51 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:51 office volumio[13106]: "progress": { Dec 27 17:47:51 office volumio[13106]: "trackProgress": 357000, Dec 27 17:47:51 office volumio[13106]: "trackDuration": 357000 Dec 27 17:47:51 office volumio[13106]: }, Dec 27 17:47:51 office volumio[13106]: "repeat": "off", Dec 27 17:47:51 office volumio[13106]: "shuffle": false Dec 27 17:47:51 office volumio[13106]: }, retryCount=0 Dec 27 17:47:51 office volumio[13106]: info: [Sendspin] updateNowPlaying called with metadata: { Dec 27 17:47:51 office volumio[13106]: "timestamp": 812564645345, Dec 27 17:47:51 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:51 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:51 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:51 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:51 office volumio[13106]: "progress": { Dec 27 17:47:51 office volumio[13106]: "trackProgress": 357000, Dec 27 17:47:51 office volumio[13106]: "trackDuration": 357000 Dec 27 17:47:51 office volumio[13106]: }, Dec 27 17:47:51 office volumio[13106]: "repeat": "off", Dec 27 17:47:51 office volumio[13106]: "shuffle": false Dec 27 17:47:51 office volumio[13106]: }, retryCount=0 Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] onMetadata callback completed successfully Dec 27 17:47:51 office volumio[13106]: info: sendMpdCommand stop took 28 milliseconds Dec 27 17:47:51 office volumio[13106]: verbose: ControllerMpd::sendMpdCommand clear Dec 27 17:47:51 office volumio[13106]: info: VolumeController:: Volume=86 Mute =false Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:51 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:51 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::updateTrackBlock Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrackBlock Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioRetrievevolume Dec 27 17:47:51 office volumio[13106]: info: Dec 27 17:47:51 office volumio[13106]: ---------------------------- MPD announces system playlist update Dec 27 17:47:51 office volumio[13106]: info: Ignoring MPD Status Update Dec 27 17:47:51 office volumio[13106]: info: sendMpdCommand clear took 98 milliseconds Dec 27 17:47:51 office volumio[13106]: verbose: ControllerMpd::sendMpdCommand load "http://127.0.0.1:37539/stream" Dec 27 17:47:51 office volumio[13106]: error: updateQueue error: null Dec 27 17:47:51 office volumio[13106]: info: ------------------------------ 52ms Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] <<< BINARY #2: type=4, timestamp=812565619473μs, serverNow=812565005428μs, diff=614045μs (614.0ms), size=134 bytes, audio=125 bytes, sync=good Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Processing audio chunk #2: scheduler=true, decoder=true, scheduler.running=true Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Decoding chunk #2: 125 bytes Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Decoded chunk #2: 125 bytes -> 3840 bytes PCM Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Scheduling chunk #2: timestamp=812565619473μs Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #1: 3840 bytes, timestamp=812565619473μs, serverNow=812565035428μs, diff=584045μs (584.0ms), playAt=2025-12-27T23:47:51.772Z, delay=584.0ms, queue=0, buffering=true, rtt=6900μs, quality=good, timeUntilPlay=584.0ms Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #1 added to queue: queue size=1 Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Scheduled chunk #2: queue size=1 Dec 27 17:47:51 office volumio[13106]: info: [AudioPlayer] HTTP request: GET /stream from 127.0.0.1 Dec 27 17:47:51 office volumio[13106]: info: [AudioPlayer] MPD connected to stream Dec 27 17:47:51 office volumio[13106]: info: [AudioPlayer] Sending WAV header: 48000Hz, 2ch, 16bit (44 bytes) Dec 27 17:47:51 office volumio[13106]: info: [AudioPlayer] Audio stream piped to MPD response Dec 27 17:47:51 office volumio[13106]: info: [AudioPlayer] Stream client connected Dec 27 17:47:51 office volumio[13106]: info: VolumeController:: Volume=86 Mute =false Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:51 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:51 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:51 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":357237,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:51 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::syncState currentStatus stop Dec 27 17:47:51 office volumio[13106]: error: [AudioPlayer] addQueueItems + MPD setup failed: [50@0] {load} No such playlist {"stack":"Error: [50@0] {load} No such playlist\n at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:63:17)\n at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12)\n at Socket.emit (node:events:514:28)\n at addChunk (node:internal/streams/readable:343:12)\n at readableAddChunk (node:internal/streams/readable:312:11)\n at Readable.push (node:internal/streams/readable:253:10)\n at Pipe.onStreamRead (node:internal/stream_base_commons:190:23)"} Dec 27 17:47:51 office volumio[13106]: info: [AudioPlayer] Trying replaceAndPlay (may fail URI explosion)... Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::ClearQueue Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::stop Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::stPlaybackTimer Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::updateTrackBlock Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrackBlock Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:51 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:51 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::serviceStop Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::serviceStop Dec 27 17:47:51 office volumio[13106]: error: WARNING: No stop method for service sendspin Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::clearPlayQueue Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::saveQueue Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioPushQueue Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::addQueueItems Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::addQueueItems Dec 27 17:47:51 office volumio[13106]: info: Preload queue cleared Dec 27 17:47:51 office volumio[13106]: info: Adding Item to queue: http://127.0.0.1:37539/stream Dec 27 17:47:51 office volumio[13106]: info: Exploding uri http://127.0.0.1:37539/stream in service sendspin Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioPushQueue Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::saveQueue Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::updateTrackBlock Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrackBlock Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioPlay Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::play index 0 Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::stop Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::play index undefined Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::startPlaybackTimer Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioGetVisibleSources Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::setConsumeUpdateService sendspin Dec 27 17:47:51 office volumio[13106]: info: [AudioPlayer] Added stream to queue and started playback via replaceAndPlay, set consume service to sendspin Dec 27 17:47:51 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:51 office volumio[13106]: info: [AudioPlayer] Stream client disconnected Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] <<< BINARY #3: type=4, timestamp=812565639473μs, serverNow=812565163428μs, diff=476045μs (476.0ms), size=75 bytes, audio=66 bytes, sync=good Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Processing audio chunk #3: scheduler=true, decoder=true, scheduler.running=true Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Decoding chunk #3: 66 bytes Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Decoded chunk #3: 66 bytes -> 3840 bytes PCM Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Scheduling chunk #3: timestamp=812565639473μs Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #2: 3840 bytes, timestamp=812565639473μs, serverNow=812565166428μs, diff=473045μs (473.0ms), playAt=2025-12-27T23:47:51.792Z, delay=473.0ms, queue=1, buffering=true, rtt=6900μs, quality=good, timeUntilPlay=473.0ms Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #2 added to queue: queue size=2 Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Scheduled chunk #3: queue size=2 Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] <<< BINARY #4: type=4, timestamp=812565659473μs, serverNow=812565168428μs, diff=491045μs (491.0ms), size=73 bytes, audio=64 bytes, sync=good Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Processing audio chunk #4: scheduler=true, decoder=true, scheduler.running=true Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Decoding chunk #4: 64 bytes Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Decoded chunk #4: 64 bytes -> 3840 bytes PCM Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Scheduling chunk #4: timestamp=812565659473μs Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #3: 3840 bytes, timestamp=812565659473μs, serverNow=812565172428μs, diff=487045μs (487.0ms), playAt=2025-12-27T23:47:51.812Z, delay=488.0ms, queue=2, buffering=true, rtt=6900μs, quality=good, timeUntilPlay=487.0ms Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #3 added to queue: queue size=3 Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Scheduled chunk #4: queue size=3 Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] <<< BINARY #5: type=4, timestamp=812565679473μs, serverNow=812565173428μs, diff=506045μs (506.0ms), size=74 bytes, audio=65 bytes, sync=good Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Processing audio chunk #5: scheduler=true, decoder=true, scheduler.running=true Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Decoding chunk #5: 65 bytes Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Decoded chunk #5: 65 bytes -> 3840 bytes PCM Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Scheduling chunk #5: timestamp=812565679473μs Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #4: 3840 bytes, timestamp=812565679473μs, serverNow=812565177428μs, diff=502045μs (502.0ms), playAt=2025-12-27T23:47:51.832Z, delay=502.0ms, queue=3, buffering=true, rtt=6900μs, quality=good, timeUntilPlay=502.0ms Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #4 added to queue: queue size=4 Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] Scheduled chunk #5: queue size=4 Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] <<< BINARY #6: type=4, timestamp=812565699473μs, serverNow=812565181428μs, diff=518045μs (518.0ms), size=74 bytes, audio=65 bytes, sync=good Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #5: 3840 bytes, timestamp=812565699473μs, serverNow=812565184428μs, diff=515045μs (515.0ms), playAt=2025-12-27T23:47:51.852Z, delay=515.0ms, queue=4, buffering=true, rtt=6900μs, quality=good, timeUntilPlay=515.0ms Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #5 added to queue: queue size=5 Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] <<< BINARY #7: type=4, timestamp=812565719473μs, serverNow=812565186428μs, diff=533045μs (533.0ms), size=76 bytes, audio=67 bytes, sync=good Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #6: 3840 bytes, timestamp=812565719473μs, serverNow=812565189428μs, diff=530045μs (530.0ms), playAt=2025-12-27T23:47:51.872Z, delay=530.0ms, queue=5, buffering=true, rtt=6900μs, quality=good, timeUntilPlay=530.0ms Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #6 added to queue: queue size=6 Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] <<< BINARY #8: type=4, timestamp=812565739473μs, serverNow=812565191428μs, diff=548045μs (548.0ms), size=76 bytes, audio=67 bytes, sync=good Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #7: 3840 bytes, timestamp=812565739473μs, serverNow=812565195428μs, diff=544045μs (544.0ms), playAt=2025-12-27T23:47:51.892Z, delay=544.0ms, queue=6, buffering=true, rtt=6900μs, quality=good, timeUntilPlay=544.0ms Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #7 added to queue: queue size=7 Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] <<< BINARY #9: type=4, timestamp=812565759473μs, serverNow=812565196428μs, diff=563045μs (563.0ms), size=76 bytes, audio=67 bytes, sync=good Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #8: 3840 bytes, timestamp=812565759473μs, serverNow=812565199428μs, diff=560045μs (560.0ms), playAt=2025-12-27T23:47:51.912Z, delay=560.0ms, queue=7, buffering=true, rtt=6900μs, quality=good, timeUntilPlay=560.0ms Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #8 added to queue: queue size=8 Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] <<< BINARY #10: type=4, timestamp=812565779473μs, serverNow=812565200428μs, diff=579045μs (579.0ms), size=74 bytes, audio=65 bytes, sync=good Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #9: 3840 bytes, timestamp=812565779473μs, serverNow=812565203428μs, diff=576045μs (576.0ms), playAt=2025-12-27T23:47:51.932Z, delay=576.0ms, queue=8, buffering=true, rtt=6900μs, quality=good, timeUntilPlay=576.0ms Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #9 added to queue: queue size=9 Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #10: 3840 bytes, timestamp=812565799473μs, serverNow=812565207428μs, diff=592045μs (592.0ms), playAt=2025-12-27T23:47:51.952Z, delay=592.0ms, queue=9, buffering=true, rtt=6900μs, quality=good, timeUntilPlay=592.0ms Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #10 added to queue: queue size=10 Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] <<< WebSocket binary message #300: 265 bytes Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #50: 3840 bytes, timestamp=812566599473μs, serverNow=812565321428μs, diff=1278045μs (1278.0ms), playAt=2025-12-27T23:47:52.752Z, delay=1278.0ms, queue=49, buffering=true, rtt=6900μs, quality=good, timeUntilPlay=1278.0ms Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:51 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":357487,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:51 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::syncState currentStatus stop Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] <<< BINARY #100: type=4, timestamp=812567579473μs, serverNow=812565444428μs, diff=2135045μs (2135.0ms), size=312 bytes, audio=303 bytes, sync=good Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #100: 3840 bytes, timestamp=812567599473μs, serverNow=812565447428μs, diff=2152045μs (2152.0ms), playAt=2025-12-27T23:47:53.752Z, delay=2152.0ms, queue=99, buffering=true, rtt=6900μs, quality=good, timeUntilPlay=2152.0ms Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] <<< WebSocket binary message #400: 214 bytes Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #150: 3840 bytes, timestamp=812568599473μs, serverNow=812565525428μs, diff=3074045μs (3074.0ms), playAt=2025-12-27T23:47:54.752Z, delay=3074.0ms, queue=149, buffering=true, rtt=6900μs, quality=good, timeUntilPlay=3074.0ms Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:51 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":357738,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:51 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:51 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:51 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:51 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:51 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:51 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:51 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] <<< BINARY #200: type=4, timestamp=812569579473μs, serverNow=812565658428μs, diff=3921045μs (3921.0ms), size=198 bytes, audio=189 bytes, sync=good Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #200: 3840 bytes, timestamp=812569599473μs, serverNow=812565662428μs, diff=3937045μs (3937.0ms), playAt=2025-12-27T23:47:55.752Z, delay=3937.0ms, queue=199, buffering=true, rtt=6900μs, quality=good, timeUntilPlay=3937.0ms Dec 27 17:47:51 office volumio[13106]: info: [SendspinClient] <<< WebSocket binary message #500: 171 bytes Dec 27 17:47:51 office volumio[13106]: info: [AudioScheduler] Chunk #250: 3840 bytes, timestamp=812570599473μs, serverNow=812565737428μs, diff=4862045μs (4862.0ms), playAt=2025-12-27T23:47:56.752Z, delay=4862.0ms, queue=249, buffering=true, rtt=562892μs, quality=good, timeUntilPlay=4862.0ms Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:51 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:51 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":357988,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:51 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:51 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:51 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:51 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:51 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:51 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:51 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:51 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:52 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:52 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:52 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:52 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":358238,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:52 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:52 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:52 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:52 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:52 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:52 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:52 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:52 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:52 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:52 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:52 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:52 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:52 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:52 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":358489,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:52 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:52 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:52 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:52 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:52 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:52 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:52 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:52 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:52 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:52 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:52 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:52 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:52 office volumio[13106]: info: [SendspinClient] <<< BINARY #300: type=4, timestamp=812571579473μs, serverNow=812566416428μs, diff=5163045μs (5163.0ms), size=194 bytes, audio=185 bytes, sync=good Dec 27 17:47:52 office volumio[13106]: info: [AudioScheduler] Chunk #300: 3840 bytes, timestamp=812571599473μs, serverNow=812566419428μs, diff=5180045μs (5180.0ms), playAt=2025-12-27T23:47:57.752Z, delay=5180.0ms, queue=299, buffering=true, rtt=12899μs, quality=good, timeUntilPlay=5180.0ms Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:52 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:52 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":358739,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:52 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:52 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:52 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:52 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:52 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:52 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:52 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:52 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:52 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:52 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:52 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:52 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:52 office volumio[13106]: info: [SendspinClient] <<< WebSocket binary message #600: 199 bytes Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:52 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:52 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":358988,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:52 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:52 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:52 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:52 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:52 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:52 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:52 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:52 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:52 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:52 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:52 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:53 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:53 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:53 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:53 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":359238,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:53 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:53 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:53 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:53 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:53 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:53 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:53 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:53 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:53 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:53 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:53 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:53 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:53 office volumio[13106]: info: [SendspinClient] <<< server/state: has_metadata=true, has_controller=false Dec 27 17:47:53 office volumio[13106]: info: [SendspinClient] <<< server/state metadata payload: { Dec 27 17:47:53 office volumio[13106]: "timestamp": 812567126197, Dec 27 17:47:53 office volumio[13106]: "progress": { Dec 27 17:47:53 office volumio[13106]: "track_progress": 2002, Dec 27 17:47:53 office volumio[13106]: "track_duration": 357000, Dec 27 17:47:53 office volumio[13106]: "playback_speed": 1000 Dec 27 17:47:53 office volumio[13106]: } Dec 27 17:47:53 office volumio[13106]: } Dec 27 17:47:53 office volumio[13106]: info: [SendspinClient] handleMetadata called with: { Dec 27 17:47:53 office volumio[13106]: "timestamp": 812567126197, Dec 27 17:47:53 office volumio[13106]: "progress": { Dec 27 17:47:53 office volumio[13106]: "track_progress": 2002, Dec 27 17:47:53 office volumio[13106]: "track_duration": 357000, Dec 27 17:47:53 office volumio[13106]: "playback_speed": 1000 Dec 27 17:47:53 office volumio[13106]: } Dec 27 17:47:53 office volumio[13106]: } Dec 27 17:47:53 office volumio[13106]: info: [SendspinClient] Metadata fields: title=null/undefined, artist=null/undefined, album=null/undefined, artwork_url=null/undefined/empty Dec 27 17:47:53 office volumio[13106]: info: [SendspinClient] Processed metadata object: { Dec 27 17:47:53 office volumio[13106]: "timestamp": 812567126197, Dec 27 17:47:53 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:53 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:53 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:53 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:53 office volumio[13106]: "progress": { Dec 27 17:47:53 office volumio[13106]: "trackProgress": 2002, Dec 27 17:47:53 office volumio[13106]: "trackDuration": 357000 Dec 27 17:47:53 office volumio[13106]: }, Dec 27 17:47:53 office volumio[13106]: "repeat": "off", Dec 27 17:47:53 office volumio[13106]: "shuffle": false Dec 27 17:47:53 office volumio[13106]: } Dec 27 17:47:53 office volumio[13106]: info: [SendspinClient] onMetadata callback exists: true Dec 27 17:47:53 office volumio[13106]: info: [SendspinClient] Calling onMetadata callback with processed metadata Dec 27 17:47:53 office volumio[13106]: info: [Sendspin] onMetadata callback received: { Dec 27 17:47:53 office volumio[13106]: "timestamp": 812567126197, Dec 27 17:47:53 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:53 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:53 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:53 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:53 office volumio[13106]: "progress": { Dec 27 17:47:53 office volumio[13106]: "trackProgress": 2002, Dec 27 17:47:53 office volumio[13106]: "trackDuration": 357000 Dec 27 17:47:53 office volumio[13106]: }, Dec 27 17:47:53 office volumio[13106]: "repeat": "off", Dec 27 17:47:53 office volumio[13106]: "shuffle": false Dec 27 17:47:53 office volumio[13106]: } Dec 27 17:47:53 office volumio[13106]: info: [Sendspin] Metadata check: hasTitle=true, hasArtist=true, title="A Better Tomorrow", artist="Dan the Automator" Dec 27 17:47:53 office volumio[13106]: info: [Sendspin] Metadata: Dan the Automator - A Better Tomorrow (A Much Better Tomorrow) Dec 27 17:47:53 office volumio[13106]: info: [Sendspin] Calling updateNowPlaying with metadata Dec 27 17:47:53 office volumio[13106]: info: [Sendspin] updateNowPlaying called with metadata: { Dec 27 17:47:53 office volumio[13106]: "timestamp": 812567126197, Dec 27 17:47:53 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:53 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:53 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:53 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:53 office volumio[13106]: "progress": { Dec 27 17:47:53 office volumio[13106]: "trackProgress": 2002, Dec 27 17:47:53 office volumio[13106]: "trackDuration": 357000 Dec 27 17:47:53 office volumio[13106]: }, Dec 27 17:47:53 office volumio[13106]: "repeat": "off", Dec 27 17:47:53 office volumio[13106]: "shuffle": false Dec 27 17:47:53 office volumio[13106]: }, retryCount=0 Dec 27 17:47:53 office volumio[13106]: info: [Sendspin] updateNowPlaying called with metadata: { Dec 27 17:47:53 office volumio[13106]: "timestamp": 812567126197, Dec 27 17:47:53 office volumio[13106]: "title": "A Better Tomorrow", Dec 27 17:47:53 office volumio[13106]: "artist": "Dan the Automator", Dec 27 17:47:53 office volumio[13106]: "album": "A Much Better Tomorrow", Dec 27 17:47:53 office volumio[13106]: "artworkUrl": "http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png", Dec 27 17:47:53 office volumio[13106]: "progress": { Dec 27 17:47:53 office volumio[13106]: "trackProgress": 2002, Dec 27 17:47:53 office volumio[13106]: "trackDuration": 357000 Dec 27 17:47:53 office volumio[13106]: }, Dec 27 17:47:53 office volumio[13106]: "repeat": "off", Dec 27 17:47:53 office volumio[13106]: "shuffle": false Dec 27 17:47:53 office volumio[13106]: }, retryCount=0 Dec 27 17:47:53 office volumio[13106]: info: [SendspinClient] onMetadata callback completed successfully Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:53 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:53 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":2201,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:53 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:53 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:53 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:53 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:53 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:53 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:53 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:53 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:53 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:53 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:53 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:53 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:53 office volumio[13106]: info: [AudioScheduler] Chunk #350: 3840 bytes, timestamp=812572599473μs, serverNow=812567402428μs, diff=5197045μs (5197.0ms), playAt=2025-12-27T23:47:58.752Z, delay=5197.0ms, queue=349, buffering=true, rtt=6883μs, quality=good, timeUntilPlay=5197.0ms Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:53 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:53 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":2450,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:53 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:53 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:53 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:53 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:53 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:53 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:53 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:53 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:53 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:53 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:53 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:53 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:53 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:53 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":2701,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:53 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:53 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:53 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:53 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:53 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:53 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:53 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:53 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:53 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:53 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:53 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:54 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:54 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:54 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:54 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":2951,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:54 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:54 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:54 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:54 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:54 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:54 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:54 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:54 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:54 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:54 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:54 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:54 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:54 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:54 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":3200,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:54 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:54 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:54 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:54 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:54 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:54 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:54 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:54 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:54 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:54 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:54 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:54 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:54 office volumio[13106]: info: [SendspinClient] <<< BINARY #400: type=4, timestamp=812573579473μs, serverNow=812568400428μs, diff=5179045μs (5179.0ms), size=195 bytes, audio=186 bytes, sync=good Dec 27 17:47:54 office volumio[13106]: info: [AudioScheduler] Chunk #400: 3840 bytes, timestamp=812573599473μs, serverNow=812568402428μs, diff=5197045μs (5197.0ms), playAt=2025-12-27T23:47:59.752Z, delay=5197.0ms, queue=399, buffering=true, rtt=6904μs, quality=good, timeUntilPlay=5197.0ms Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:54 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:54 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":3450,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:54 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:54 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:54 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:54 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:54 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:54 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:54 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:54 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:54 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:54 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:54 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:54 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:54 office volumio[13106]: info: [SendspinClient] <<< WebSocket binary message #700: 180 bytes Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:54 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:54 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":3701,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:54 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:54 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:54 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:54 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:54 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:54 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:54 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:54 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:54 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:54 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:54 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:55 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:55 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:55 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:55 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":3950,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:55 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:55 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:55 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:55 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:55 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:55 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:55 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:55 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:55 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:55 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:55 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:55 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:55 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:55 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":4201,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:55 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:55 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:55 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:55 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:55 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:55 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:55 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:55 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:55 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:55 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:55 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:55 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:55 office volumio[13106]: info: [AudioScheduler] Chunk #450: 3840 bytes, timestamp=812574599473μs, serverNow=812569403428μs, diff=5196045μs (5196.0ms), playAt=2025-12-27T23:48:00.752Z, delay=5196.0ms, queue=449, buffering=true, rtt=6906μs, quality=good, timeUntilPlay=5196.0ms Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:55 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:55 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":4450,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:55 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:55 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:55 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:55 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:55 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:55 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:55 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:55 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:55 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:55 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:55 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:55 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] HANG DETECTED: Buffering for 5.0s (target: 550, have: 454). Forcing playback start. Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 10 consecutive late buffers (last: 3839ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 20 consecutive late buffers (last: 3639ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 30 consecutive late buffers (last: 3439ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 40 consecutive late buffers (last: 3239ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 50 consecutive late buffers (last: 3039ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 60 consecutive late buffers (last: 2839ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 70 consecutive late buffers (last: 2639ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 80 consecutive late buffers (last: 2439ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 90 consecutive late buffers (last: 2239ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 100 consecutive late buffers (last: 2039ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 110 consecutive late buffers (last: 1839ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 120 consecutive late buffers (last: 1639ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 130 consecutive late buffers (last: 1439ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 140 consecutive late buffers (last: 1239ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 150 consecutive late buffers (last: 1039ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 160 consecutive late buffers (last: 839ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 170 consecutive late buffers (last: 639ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 180 consecutive late buffers (last: 439ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: warn: [AudioScheduler] Dropped 190 consecutive late buffers (last: 239ms late). Clock sync quality: good, rtt: 6906μs Dec 27 17:47:55 office volumio[13106]: info: [AudioScheduler] Playing buffer #1: 3840 bytes, 39ms late, queue=254, timestamp=812569599473μs, serverNow=812569649428μs, timestampDiff=-50.0ms, sync=good, rtt=6906μs Dec 27 17:47:55 office volumio[13106]: info: [Sendspin] Handling audio chunk #1: 3840 bytes PCM, playerActive=true Dec 27 17:47:55 office volumio[13106]: warn: [AudioPlayer] No MPD client connected! Chunk will be buffered. (warning #1) Dec 27 17:47:55 office volumio[13106]: info: [AudioPlayer] Pushed chunk #1: 3840 bytes, backpressured=false, hasClient=false, isPlaying=true Dec 27 17:47:55 office volumio[13106]: info: [AudioScheduler] Playing buffer #2: 3840 bytes, 19ms late, queue=253, timestamp=812569619473μs, serverNow=812569651428μs, timestampDiff=-32.0ms, sync=good, rtt=6906μs Dec 27 17:47:55 office volumio[13106]: info: [Sendspin] Handling audio chunk #2: 3840 bytes PCM, playerActive=true Dec 27 17:47:55 office volumio[13106]: warn: [AudioPlayer] No MPD client connected! Chunk will be buffered. (warning #2) Dec 27 17:47:55 office volumio[13106]: info: [AudioPlayer] Pushed chunk #2: 3840 bytes, backpressured=false, hasClient=false, isPlaying=true Dec 27 17:47:55 office volumio[13106]: info: [AudioScheduler] Playing buffer #3: 3840 bytes, 1.0ms early, queue=252, timestamp=812569639473μs, serverNow=812569651428μs, timestampDiff=-12.0ms, sync=good, rtt=6906μs Dec 27 17:47:55 office volumio[13106]: info: [Sendspin] Handling audio chunk #3: 3840 bytes PCM, playerActive=true Dec 27 17:47:55 office volumio[13106]: warn: [AudioPlayer] No MPD client connected! Chunk will be buffered. (warning #3) Dec 27 17:47:55 office volumio[13106]: info: [AudioPlayer] Pushed chunk #3: 3840 bytes, backpressured=false, hasClient=false, isPlaying=true Dec 27 17:47:55 office volumio[13106]: info: [AudioScheduler] Playing buffer #4: 3840 bytes, 21.0ms early, queue=251, timestamp=812569659473μs, serverNow=812569652428μs, timestampDiff=7.0ms, sync=good, rtt=6906μs Dec 27 17:47:55 office volumio[13106]: info: [Sendspin] Handling audio chunk #4: 3840 bytes PCM, playerActive=true Dec 27 17:47:55 office volumio[13106]: warn: [AudioPlayer] No MPD client connected! Chunk will be buffered. (warning #4) Dec 27 17:47:55 office volumio[13106]: info: [AudioPlayer] Pushed chunk #4: 3840 bytes, backpressured=false, hasClient=false, isPlaying=true Dec 27 17:47:55 office volumio[13106]: info: [AudioScheduler] Playing buffer #5: 3840 bytes, 41.0ms early, queue=250, timestamp=812569679473μs, serverNow=812569652428μs, timestampDiff=27.0ms, sync=good, rtt=6906μs Dec 27 17:47:55 office volumio[13106]: info: [Sendspin] Handling audio chunk #5: 3840 bytes PCM, playerActive=true Dec 27 17:47:55 office volumio[13106]: warn: [AudioPlayer] No MPD client connected! Chunk will be buffered. (warning #5) Dec 27 17:47:55 office volumio[13106]: info: [AudioPlayer] Pushed chunk #5: 3840 bytes, backpressured=true, hasClient=false, isPlaying=true Dec 27 17:47:55 office volumio[13106]: info: [AudioPlayer] Pushed chunk #6: 3840 bytes, backpressured=true, hasClient=false, isPlaying=true Dec 27 17:47:55 office volumio[13106]: info: [AudioPlayer] Pushed chunk #7: 3840 bytes, backpressured=true, hasClient=false, isPlaying=true Dec 27 17:47:55 office volumio[13106]: info: [AudioPlayer] Pushed chunk #8: 3840 bytes, backpressured=true, hasClient=false, isPlaying=true Dec 27 17:47:55 office volumio[13106]: info: [AudioPlayer] Pushed chunk #9: 3840 bytes, backpressured=true, hasClient=false, isPlaying=true Dec 27 17:47:55 office volumio[13106]: info: [AudioPlayer] Pushed chunk #10: 3840 bytes, backpressured=true, hasClient=false, isPlaying=true Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:55 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:55 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":4701,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:55 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:55 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:55 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:55 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:55 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:55 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:55 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:55 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:55 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:55 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:55 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:56 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:56 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:56 office volumio[13106]: (node:13106) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 21 drain listeners added to [Readable]. Use emitter.setMaxListeners() to increase limit Dec 27 17:47:56 office volumio[13106]: (Use `node --trace-warnings ...` to show where the warning was created) Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:56 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:56 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":4951,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:56 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:56 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:56 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:56 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:56 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:56 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:56 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:56 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:56 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:56 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:56 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:56 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:56 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:56 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":5201,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:56 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:56 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:56 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:56 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:56 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:56 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:56 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:56 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:56 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:56 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:56 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:56 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:56 office volumio[13106]: info: [SendspinClient] <<< BINARY #500: type=4, timestamp=812575579473μs, serverNow=812570407428μs, diff=5172045μs (5172.0ms), size=357 bytes, audio=348 bytes, sync=good Dec 27 17:47:56 office volumio[13106]: info: [AudioScheduler] Chunk #500: 3840 bytes, timestamp=812575599473μs, serverNow=812570409428μs, diff=5190045μs (5190.0ms), playAt=2025-12-27T23:48:01.752Z, delay=5190.0ms, queue=257, buffering=false, rtt=8906μs, quality=good, timeUntilPlay=5190.0ms Dec 27 17:47:56 office volumio[13106]: info: [AudioScheduler] Playing buffer #50: 3840 bytes, 47.0ms early, queue=255, timestamp=812570579473μs, serverNow=812570532428μs, timestampDiff=47.0ms, sync=good, rtt=8906μs Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:56 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:56 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":5451,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:56 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:56 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:56 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:56 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:56 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:56 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:56 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:56 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:56 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:56 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:56 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:56 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:56 office volumio[13106]: info: [SendspinClient] <<< WebSocket binary message #800: 191 bytes Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:56 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:56 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":5702,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:56 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:56 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:56 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:56 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:56 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:56 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:56 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:56 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:56 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:56 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:56 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:57 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:57 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:57 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:57 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":5951,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:57 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:57 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:57 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:57 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:57 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:57 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:57 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:57 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:57 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:57 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:57 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:57 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:57 office sudo[14121]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 27 17:47:57 office sudo[14121]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 27 17:47:57 office sudo[14121]: pam_unix(sudo:session): session closed for user root Dec 27 17:47:57 office sudo[14123]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 27 17:47:57 office sudo[14123]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 27 17:47:57 office sudo[14123]: pam_unix(sudo:session): session closed for user root Dec 27 17:47:57 office volumio[13106]: verbose: New Socket.io Connection to 192.168.86.66 from 192.168.86.63 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Edg/143.0.0.0 Engine version: 3 Transport: polling Total Clients: 7 Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:57 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:57 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":6201,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:57 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:57 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:57 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:57 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:57 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:57 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:57 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:57 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:57 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:57 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:57 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:57 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:57 office volumio[13106]: info: [AudioScheduler] Chunk #550: 3840 bytes, timestamp=812576599473μs, serverNow=812571405428μs, diff=5194045μs (5194.0ms), playAt=2025-12-27T23:48:02.752Z, delay=5194.0ms, queue=257, buffering=false, rtt=33901μs, quality=good, timeUntilPlay=5194.0ms Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Dec 27 17:47:57 office volumio[13106]: info: [AudioScheduler] Playing buffer #100: 3840 bytes, 46.0ms early, queue=255, timestamp=812571579473μs, serverNow=812571533428μs, timestampDiff=46.0ms, sync=good, rtt=33901μs Dec 27 17:47:57 office volumio[13106]: info: [Sendspin] Handling audio chunk #100: 3840 bytes PCM, playerActive=true Dec 27 17:47:57 office volumio[13106]: warn: [AudioPlayer] No MPD client connected! Chunk will be buffered. (warning #100) Dec 27 17:47:57 office volumio[13106]: info: [AudioPlayer] Pushed chunk #100: 3840 bytes, backpressured=true, hasClient=false, isPlaying=true Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioGetVisibleSources Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 27 17:47:57 office volumio[13106]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Dec 27 17:47:57 office volumio[13106]: info: Received Get System Info Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:47:57 office volumio[13106]: info: Discovery: Getting this device information Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:57 office volumio[13106]: info: Listing playlists Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:57 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:57 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":6451,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:57 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:57 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:57 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:57 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:57 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:57 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:57 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:57 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:57 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:57 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:57 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:57 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:57 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:57 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":6701,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:57 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:57 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:57 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:57 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:57 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:57 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:57 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:57 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:57 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:57 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:57 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:58 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:58 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:58 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:58 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":6951,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:58 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:58 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:58 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:58 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:58 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:58 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:58 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:58 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:58 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:58 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:58 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:58 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:58 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:58 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":7201,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:58 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:58 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:58 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:58 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:58 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:58 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:58 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:58 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:58 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:58 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:58 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:58 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:58 office volumio[13106]: info: [SendspinClient] <<< BINARY #600: type=4, timestamp=812577579473μs, serverNow=812572401428μs, diff=5178045μs (5178.0ms), size=187 bytes, audio=178 bytes, sync=good Dec 27 17:47:58 office volumio[13106]: info: [AudioScheduler] Chunk #600: 3840 bytes, timestamp=812577599473μs, serverNow=812572403428μs, diff=5196045μs (5196.0ms), playAt=2025-12-27T23:48:03.752Z, delay=5196.0ms, queue=257, buffering=false, rtt=7908μs, quality=good, timeUntilPlay=5196.0ms Dec 27 17:47:58 office volumio[13106]: info: [AudioScheduler] Playing buffer #150: 3840 bytes, 47.0ms early, queue=255, timestamp=812572579473μs, serverNow=812572532428μs, timestampDiff=47.0ms, sync=good, rtt=7908μs Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:58 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:58 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":7451,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:58 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:58 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:58 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:58 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:58 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:58 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:58 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:58 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:58 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:58 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:58 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:58 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:58 office volumio[13106]: info: [SendspinClient] <<< WebSocket binary message #900: 190 bytes Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:58 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:58 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":7701,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:58 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:58 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:58 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:58 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:58 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:58 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:58 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:58 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:58 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:58 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:58 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:59 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:59 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:59 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:59 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":7952,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:59 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:59 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:59 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:59 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:59 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:59 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:59 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:59 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:59 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:59 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:59 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:59 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 27 17:47:59 office volumio[13106]: info: Received Get System Info Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 27 17:47:59 office volumio[13106]: info: Discovery: Getting this device information Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:59 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:59 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":8202,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:59 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:59 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:59 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:59 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:59 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:59 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:59 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:59 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:59 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:59 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:59 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:59 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:59 office volumio[13106]: info: [AudioScheduler] Chunk #650: 3840 bytes, timestamp=812578599473μs, serverNow=812573405428μs, diff=5194045μs (5194.0ms), playAt=2025-12-27T23:48:04.752Z, delay=5194.0ms, queue=257, buffering=false, rtt=5888μs, quality=good, timeUntilPlay=5194.0ms Dec 27 17:47:59 office volumio[13106]: info: [AudioScheduler] Playing buffer #200: 3840 bytes, 40.0ms early, queue=255, timestamp=812573579473μs, serverNow=812573539428μs, timestampDiff=40.0ms, sync=good, rtt=5888μs Dec 27 17:47:59 office volumio[13106]: info: [Sendspin] Handling audio chunk #200: 3840 bytes PCM, playerActive=true Dec 27 17:47:59 office volumio[13106]: warn: [AudioPlayer] No MPD client connected! Chunk will be buffered. (warning #200) Dec 27 17:47:59 office volumio[13106]: info: [AudioPlayer] Pushed chunk #200: 3840 bytes, backpressured=true, hasClient=false, isPlaying=true Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::servicePushState Dec 27 17:47:59 office volumio[13106]: info: CorePlayQueue::getTrack 0 Dec 27 17:47:59 office volumio[13106]: verbose: STATE SERVICE {"service":"sendspin","title":"A Better Tomorrow","artist":"Dan the Automator","album":"A Much Better Tomorrow","albumart":"http://192.168.86.37:8095/imageproxy?provider=filesystem_local--qxdE7RLF&size=500&fmt=jpeg&path=Dan%2BThe%2BAutomator%252FA%2BMuch%2BBetter%2BTomorrow%252Fcover.png","uri":"http://127.0.0.1:37539/stream","type":"webradio","trackType":"sendspin","status":"play","position":8452,"duration":357000,"samplerate":"48000","bitdepth":"16","channels":"2","volume":100,"mute":false} Dec 27 17:47:59 office volumio[13106]: verbose: CURRENT POSITION 0 Dec 27 17:47:59 office volumio[13106]: info: CoreStateMachine::syncState stateService play Dec 27 17:47:59 office volumio[13106]: info: CoreStateMachine::syncState currentStatus play Dec 27 17:47:59 office volumio[13106]: info: Received an update from plugin. extracting info from payload Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt Dec 27 17:47:59 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:59 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:59 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:59 office volumio[13106]: info: CoreStateMachine::pushState Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::volumioPushState Dec 27 17:47:59 office volumio[13106]: info: MRS: Pushing multiroomSync output update for this device Dec 27 17:47:59 office volumio[13106]: info: MRS: Pushing multiroomSync output Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::volumioGetState Dec 27 17:47:59 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:59 office volumio[13106]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.ieyQaaQAs9hVQGAq5VJUAKOFUrI3.33b78171fb50fdd4c74d4838ba48f776.state.track' Dec 27 17:47:59 office volumio[13106]: info: CoreCommandRouter::volumioNext Dec 27 17:47:59 office volumio[13106]: info: CoreStateMachine::next Dec 27 17:47:59 office volumio[13106]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 27 17:47:59 office volumio[13106]: TypeError: Cannot read properties of undefined (reading 'next') Dec 27 17:47:59 office volumio[13106]: at CoreStateMachine.next (/volumio/app/statemachine.js:1172:29) Dec 27 17:47:59 office volumio[13106]: at CoreCommandRouter.volumioNext (/volumio/app/index.js:103:28) Dec 27 17:47:59 office volumio[13106]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:274:26) Dec 27 17:47:59 office volumio[13106]: at Socket.emit (node:events:514:28) Dec 27 17:47:59 office volumio[13106]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Dec 27 17:47:59 office volumio[13106]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Dec 27 17:47:59 office volumio[13106]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 27 17:48:00 office sudo[14143]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-27 17:47' Dec 27 17:48:00 office sudo[14143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"