-- Logs begin at Thu 2025-01-16 22:10:51 UTC, end at Thu 2025-01-16 22:55:17 UTC. -- Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: verbose: New Socket.io Connection to 192.168.0.109 from 192.168.0.122 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_1_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 8 Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: Received Get System Info Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: Discovery: Getting this device information Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioGetState Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioGetState Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioGetVisibleSources Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioGetState Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: Received Get System Info Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: Discovery: Getting this device information Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioGetState Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioGetState Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: Listing playlists Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioGetQueue Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::getQueue Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CorePlayQueue::getQueue Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::getUIConfigOnPlugin Jan 16 22:54:02 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioVolatilePlay Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::volatilePlay Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: Spotify Play Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: Sending Spotify command to local API: /player/resume Jan 16 22:54:07 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:07Z" level=trace msg="seek to 121323ms (diff: 133ms, samples: 5350344, bytes: 5082112)" uri="spotify:track:6mFkJmJqdDVQ1REhVfGgd1" Jan 16 22:54:07 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:07Z" level=debug msg="resume track at 121190ms" Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jan 16 22:54:07 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:07Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 16 22:54:07 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:07Z" level=trace msg="scheduling prefetch in 183s" Jan 16 22:54:07 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:07Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 16 22:54:07 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:07Z" level=trace msg="emitting websocket event: playing" Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6mFkJmJqdDVQ1REhVfGgd1","play_origin":"playlist/ondemand"}} Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: PUSH STATE SPOTIFY Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: {"status":"play","service":"spop","title":"Wish You Were Here","artist":"Pink Floyd","album":"Wish You Were Here","albumart":"https://i.scdn.co/image/ab67616d00001e021a84d71391df7469c5ab8539","uri":"spotify:track:6mFkJmJqdDVQ1REhVfGgd1","trackType":"spotify","seek":121323,"duration":334,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::servicePushState Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:07 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:08 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: PUSH STATE SPOTIFY Jan 16 22:54:08 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: {"status":"play","service":"spop","title":"Wish You Were Here","artist":"Pink Floyd","album":"Wish You Were Here","albumart":"https://i.scdn.co/image/ab67616d00001e021a84d71391df7469c5ab8539","uri":"spotify:track:6mFkJmJqdDVQ1REhVfGgd1","trackType":"spotify","seek":121323,"duration":334,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 16 22:54:08 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::servicePushState Jan 16 22:54:08 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:08 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:08 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:08 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:10 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:10Z" level=debug msg="fetched chunk 13/27, size: 524288" uri="spotify:track:6mFkJmJqdDVQ1REhVfGgd1" Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPause Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pause Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::stPlaybackTimer Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::servicePause Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::servicePause Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: info: Spotify Received pause Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: SPOTIFY PAUSE Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: {"status":"play","title":"Wish You Were Here","artist":"Pink Floyd","album":"Wish You Were Here","albumart":"https://i.scdn.co/image/ab67616d00001e021a84d71391df7469c5ab8539","uri":"spotify:track:6mFkJmJqdDVQ1REhVfGgd1","trackType":"spotify","codec":"ogg","seek":121323,"duration":334,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":true,"stream":false,"volatile":true,"service":"spop"} Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: info: Sending Spotify command to local API: /player/pause Jan 16 22:54:19 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:19Z" level=debug msg="pause track at 133187ms" Jan 16 22:54:19 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:19Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 16 22:54:19 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:19Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 16 22:54:19 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:19Z" level=trace msg="emitting websocket event: paused" Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6mFkJmJqdDVQ1REhVfGgd1","play_origin":"playlist/ondemand"}} Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: PUSH STATE SPOTIFY Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: {"status":"pause","service":"spop","title":"Wish You Were Here","artist":"Pink Floyd","album":"Wish You Were Here","albumart":"https://i.scdn.co/image/ab67616d00001e021a84d71391df7469c5ab8539","uri":"spotify:track:6mFkJmJqdDVQ1REhVfGgd1","trackType":"spotify","seek":132323,"duration":334,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::servicePushState Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:19 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: info: Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: ---------------------------- MPD announces system playlist update Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: info: Ignoring MPD Status Update Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: info: Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: ---------------------------- MPD announces state update: player Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: info: ControllerMpd::getState Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: verbose: ControllerMpd::sendMpdCommand status Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: info: ------------------------------ 8ms Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: info: sendMpdCommand status took 5 milliseconds Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: verbose: ControllerMpd::parseState Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: verbose: ControllerMpd::parseTrackInfo Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: info: ControllerMpd::pushState Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::servicePushState Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:22 volumio-luisterruimte-nederhorst volumio[1236]: info: ------------------------------ 49ms Jan 16 22:54:24 volumio-luisterruimte-nederhorst volumio[1236]: info: Executing endpoint metavolumio Jan 16 22:54:24 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 16 22:54:24 volumio-luisterruimte-nederhorst volumio[1236]: info: Executing endpoint metavolumio Jan 16 22:54:24 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPause Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pause Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::stPlaybackTimer Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::servicePause Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::servicePause Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: ControllerMpd::pause Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: verbose: ControllerMpd::sendMpdCommand pause Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: ---------------------------- MPD announces state update: player Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: sendMpdCommand pause took 2 milliseconds Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: ControllerMpd::getState Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: verbose: ControllerMpd::sendMpdCommand status Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: sendMpdCommand status took 1 milliseconds Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: verbose: ControllerMpd::parseState Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: sendMpdCommand playlistinfo took 1 milliseconds Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: verbose: ControllerMpd::parseTrackInfo Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: ControllerMpd::pushState Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::servicePushState Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:26 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:27 volumio-luisterruimte-nederhorst volumio[1236]: info: ------------------------------ 51ms Jan 16 22:54:27 volumio-luisterruimte-nederhorst volumio[1236]: info: camilladsp spawned new process with pid 6161, instance 1, run: true Jan 16 22:54:35 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:35Z" level=debug msg="handling resume player command from 1e74a5f9c4548f5af327b2184c8dbd7e2846f366" Jan 16 22:54:35 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:35Z" level=trace msg="seek to 133187ms (diff: 107ms, samples: 5873546, bytes: 5603392)" uri="spotify:track:6mFkJmJqdDVQ1REhVfGgd1" Jan 16 22:54:35 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:35Z" level=debug msg="resume track at 133080ms" Jan 16 22:54:35 volumio-luisterruimte-nederhorst volumio[1236]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jan 16 22:54:35 volumio-luisterruimte-nederhorst volumio[1236]: info: FusionDsp - ---- read samplerate from file: 44100 Jan 16 22:54:35 volumio-luisterruimte-nederhorst volumio[1236]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jan 16 22:54:35 volumio-luisterruimte-nederhorst volumio[1236]: info: FusionDsp - {"Reload":{"result":"Ok"}} Jan 16 22:54:35 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:35Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 16 22:54:35 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:35Z" level=trace msg="scheduling prefetch in 171s" Jan 16 22:54:35 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:35Z" level=debug msg="sending successful reply for dealer request" Jan 16 22:54:36 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:36Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 16 22:54:36 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:36Z" level=trace msg="emitting websocket event: playing" Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6mFkJmJqdDVQ1REhVfGgd1","play_origin":"playlist/ondemand"}} Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: info: Spotify is playing in volatile mode Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: UNSET VOLATILE Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: {"status":"pause","title":"Bryan Adams - Run to You","artist":"80s80s Digital Web","album":null,"albumart":"/albumart","uri":"http://streams.80s80s.de/web/mp3-192/volumio","trackType":"","codec":"","seek":128840,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"repeat":false,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":true,"stream":false,"volatile":true} Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: info: Setting Spotify stop after unset volatile call Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: PUSH STATE SPOTIFY Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: {"status":"play","service":"spop","title":"Wish You Were Here","artist":"Pink Floyd","album":"Wish You Were Here","albumart":"https://i.scdn.co/image/ab67616d00001e021a84d71391df7469c5ab8539","uri":"spotify:track:6mFkJmJqdDVQ1REhVfGgd1","trackType":"spotify","seek":132323,"duration":334,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::servicePushState Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: PUSH STATE SPOTIFY Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: {"status":"play","service":"spop","title":"Wish You Were Here","artist":"Pink Floyd","album":"Wish You Were Here","albumart":"https://i.scdn.co/image/ab67616d00001e021a84d71391df7469c5ab8539","uri":"spotify:track:6mFkJmJqdDVQ1REhVfGgd1","trackType":"spotify","seek":132323,"duration":334,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::servicePushState Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: info: Spotify Stop Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: SPOTIFY STOP Jan 16 22:54:36 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: {"status":"play","title":"Wish You Were Here","artist":"Pink Floyd","album":"Wish You Were Here","albumart":"https://i.scdn.co/image/ab67616d00001e021a84d71391df7469c5ab8539","uri":"spotify:track:6mFkJmJqdDVQ1REhVfGgd1","trackType":"spotify","codec":"ogg","seek":132323,"duration":334,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":true,"stream":false,"volatile":true,"service":"spop"} Jan 16 22:54:37 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:37Z" level=debug msg="fetched chunk 14/27, size: 524288" uri="spotify:track:6mFkJmJqdDVQ1REhVfGgd1" Jan 16 22:54:38 volumio-luisterruimte-nederhorst volumio[1236]: info: Executing endpoint metavolumio Jan 16 22:54:38 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 16 22:54:38 volumio-luisterruimte-nederhorst volumio[1236]: info: Executing endpoint metavolumio Jan 16 22:54:38 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 16 22:54:38 volumio-luisterruimte-nederhorst volumio[1236]: info: Executing endpoint metavolumio Jan 16 22:54:38 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 16 22:54:45 volumio-luisterruimte-nederhorst volumiologrotate[538]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Jan 16 22:54:45 volumio-luisterruimte-nederhorst volumiologrotate[538]: ls: cannot access 'LUISTERRUIMTE': No such file or directory Jan 16 22:54:45 volumio-luisterruimte-nederhorst volumiologrotate[538]: ls: cannot access 'NEDERHORST': No such file or directory Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=debug msg="handling play player command from 1e74a5f9c4548f5af327b2184c8dbd7e2846f366" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=debug msg="resolved context of track" uri="spotify:playlist:1DTzz7Nh2rJBnyFbjsH1Mh" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=trace msg="fetched new page 0 with 1967 items (list: 1967)" uri="spotify:playlist:1DTzz7Nh2rJBnyFbjsH1Mh" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:21cp8L9Pei4AgysZVihjSv" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=trace msg="emitting websocket event: will_play" Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:21cp8L9Pei4AgysZVihjSv","play_origin":"playlist/ondemand"}} Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=debug msg="selected format OGG_VORBIS_320 (be69a983743db58e7c4ca1a8f4ac3fb01896d776)" uri="spotify:track:21cp8L9Pei4AgysZVihjSv" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=debug msg="requested aes key for file be69a983743db58e7c4ca1a8f4ac3fb01896d776, gid: 21cp8L9Pei4AgysZVihjSv" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=debug msg="fetched first chunk of 48, total size is 24752440 bytes" uri="spotify:track:21cp8L9Pei4AgysZVihjSv" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:21cp8L9Pei4AgysZVihjSv" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=info msg="loaded track \"Child in Time\" (paused: false, position: 0ms, duration: 619266ms, prefetched: false)" uri="spotify:track:21cp8L9Pei4AgysZVihjSv" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=debug msg="fetched chunk 1/47, size: 524288" uri="spotify:track:21cp8L9Pei4AgysZVihjSv" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=debug msg="fetched chunk 3/47, size: 524288" uri="spotify:track:21cp8L9Pei4AgysZVihjSv" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=trace msg="scheduling prefetch in 589s" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=trace msg="emitting websocket event: metadata" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=debug msg="sending successful reply for dealer request" Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:21cp8L9Pei4AgysZVihjSv","name":"Child in Time","artist_names":["Deep Purple"],"album_name":"Deepest Purple: The Very Best of Deep Purple","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0225b36a6170824fefd38d337e","position":0,"duration":619266,"release_date":"year:1990 month:7 day:23","track_number":5,"disc_number":1}} Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=debug msg="fetched chunk 2/47, size: 524288" uri="spotify:track:21cp8L9Pei4AgysZVihjSv" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 16 22:54:49 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:49Z" level=trace msg="emitting websocket event: playing" Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:21cp8L9Pei4AgysZVihjSv","play_origin":"playlist/ondemand"}} Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: PUSH STATE SPOTIFY Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: {"status":"play","service":"spop","title":"Child in Time","artist":"Deep Purple","album":"Deepest Purple: The Very Best of Deep Purple","albumart":"https://i.scdn.co/image/ab67616d00001e0225b36a6170824fefd38d337e","uri":"spotify:track:21cp8L9Pei4AgysZVihjSv","trackType":"spotify","seek":0,"duration":619,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::servicePushState Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: PUSH STATE SPOTIFY Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: {"status":"play","service":"spop","title":"Child in Time","artist":"Deep Purple","album":"Deepest Purple: The Very Best of Deep Purple","albumart":"https://i.scdn.co/image/ab67616d00001e0225b36a6170824fefd38d337e","uri":"spotify:track:21cp8L9Pei4AgysZVihjSv","trackType":"spotify","seek":0,"duration":619,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::servicePushState Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:49 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:51 volumio-luisterruimte-nederhorst volumio[1236]: info: Executing endpoint metavolumio Jan 16 22:54:51 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 16 22:54:51 volumio-luisterruimte-nederhorst volumio[1236]: info: Executing endpoint metavolumio Jan 16 22:54:51 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 16 22:54:51 volumio-luisterruimte-nederhorst volumio[1236]: info: Executing endpoint metavolumio Jan 16 22:54:51 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 16 22:54:54 volumio-luisterruimte-nederhorst volumio[1236]: error: Failed request for metavolumio API Jan 16 22:54:55 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:55Z" level=debug msg="update volume to 30930/65535" Jan 16 22:54:55 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:55Z" level=debug msg="put connect state because VOLUME_CHANGED" Jan 16 22:54:55 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:55Z" level=trace msg="emitting websocket event: volume" Jan 16 22:54:55 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"volume","data":{"value":48,"max":100}} Jan 16 22:54:55 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: RECEIVED SPOTIFY VOLUME 48 Jan 16 22:54:55 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:55Z" level=debug msg="update volume to 33751/65535" Jan 16 22:54:55 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:55Z" level=debug msg="put connect state because VOLUME_CHANGED" Jan 16 22:54:55 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:55Z" level=trace msg="emitting websocket event: volume" Jan 16 22:54:55 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"volume","data":{"value":52,"max":100}} Jan 16 22:54:55 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: RECEIVED SPOTIFY VOLUME 52 Jan 16 22:54:55 volumio-luisterruimte-nederhorst volumio[1236]: info: Setting Volumio Volume from Spotify: 52 Jan 16 22:54:55 volumio-luisterruimte-nederhorst volumio[1236]: info: VolumeController::SetAlsaVolume52 Jan 16 22:54:55 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:55 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 16 22:54:55 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:55 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:55 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:56 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:56Z" level=debug msg="update volume to 41229/65535" Jan 16 22:54:56 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:56Z" level=debug msg="put connect state because VOLUME_CHANGED" Jan 16 22:54:56 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:56Z" level=trace msg="emitting websocket event: volume" Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"volume","data":{"value":63,"max":100}} Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: RECEIVED SPOTIFY VOLUME 63 Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: Setting Volumio Volume from Spotify: 63 Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: VolumeController::SetAlsaVolume63 Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:56 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:56Z" level=debug msg="update volume to 42148/65535" Jan 16 22:54:56 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:56Z" level=debug msg="put connect state because VOLUME_CHANGED" Jan 16 22:54:56 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:56Z" level=trace msg="emitting websocket event: volume" Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"volume","data":{"value":65,"max":100}} Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: RECEIVED SPOTIFY VOLUME 65 Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: Setting Volumio Volume from Spotify: 65 Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: VolumeController::SetAlsaVolume65 Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:56 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:56Z" level=debug msg="update volume to 42673/65535" Jan 16 22:54:56 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:56Z" level=debug msg="put connect state because VOLUME_CHANGED" Jan 16 22:54:56 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:56Z" level=trace msg="emitting websocket event: volume" Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"volume","data":{"value":66,"max":100}} Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: RECEIVED SPOTIFY VOLUME 66 Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: Setting Volumio Volume from Spotify: 66 Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: VolumeController::SetAlsaVolume66 Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:56 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:56Z" level=debug msg="update volume to 43394/65535" Jan 16 22:54:56 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:56Z" level=debug msg="put connect state because VOLUME_CHANGED" Jan 16 22:54:56 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:56Z" level=trace msg="emitting websocket event: volume" Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"volume","data":{"value":67,"max":100}} Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: RECEIVED SPOTIFY VOLUME 67 Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: Setting Volumio Volume from Spotify: 67 Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: VolumeController::SetAlsaVolume67 Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:56 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:57 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:57Z" level=debug msg="update volume to 43460/65535" Jan 16 22:54:57 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:57Z" level=debug msg="put connect state because VOLUME_CHANGED" Jan 16 22:54:57 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:57Z" level=trace msg="emitting websocket event: volume" Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"volume","data":{"value":67,"max":100}} Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: RECEIVED SPOTIFY VOLUME 67 Jan 16 22:54:57 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:57Z" level=debug msg="update volume to 51529/65535" Jan 16 22:54:57 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:57Z" level=debug msg="put connect state because VOLUME_CHANGED" Jan 16 22:54:57 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:57Z" level=trace msg="emitting websocket event: volume" Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"volume","data":{"value":79,"max":100}} Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: RECEIVED SPOTIFY VOLUME 79 Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: Setting Volumio Volume from Spotify: 79 Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: VolumeController::SetAlsaVolume79 Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:57 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:57Z" level=debug msg="update volume to 53038/65535" Jan 16 22:54:57 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:57Z" level=debug msg="put connect state because VOLUME_CHANGED" Jan 16 22:54:57 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:57Z" level=trace msg="emitting websocket event: volume" Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"volume","data":{"value":81,"max":100}} Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: RECEIVED SPOTIFY VOLUME 81 Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: Setting Volumio Volume from Spotify: 81 Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: VolumeController::SetAlsaVolume81 Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:57 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:57Z" level=debug msg="update volume to 54153/65535" Jan 16 22:54:57 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:57Z" level=debug msg="put connect state because VOLUME_CHANGED" Jan 16 22:54:57 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:57Z" level=trace msg="emitting websocket event: volume" Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"volume","data":{"value":83,"max":100}} Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: RECEIVED SPOTIFY VOLUME 83 Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: Setting Volumio Volume from Spotify: 83 Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: VolumeController::SetAlsaVolume83 Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:57 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:57 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:57Z" level=debug msg="update volume to 55202/65535" Jan 16 22:54:58 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:58Z" level=debug msg="put connect state because VOLUME_CHANGED" Jan 16 22:54:58 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:58Z" level=trace msg="emitting websocket event: volume" Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"volume","data":{"value":85,"max":100}} Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: RECEIVED SPOTIFY VOLUME 85 Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: Setting Volumio Volume from Spotify: 85 Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: VolumeController::SetAlsaVolume85 Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:58 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:58Z" level=debug msg="update volume to 59466/65535" Jan 16 22:54:58 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:58Z" level=debug msg="put connect state because VOLUME_CHANGED" Jan 16 22:54:58 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:58Z" level=trace msg="emitting websocket event: volume" Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"volume","data":{"value":91,"max":100}} Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: RECEIVED SPOTIFY VOLUME 91 Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: Setting Volumio Volume from Spotify: 91 Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: VolumeController::SetAlsaVolume91 Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:58 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:58Z" level=debug msg="update volume to 39458/65535" Jan 16 22:54:58 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:58Z" level=debug msg="put connect state because VOLUME_CHANGED" Jan 16 22:54:58 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:58Z" level=trace msg="emitting websocket event: volume" Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"volume","data":{"value":61,"max":100}} Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: RECEIVED SPOTIFY VOLUME 61 Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: Setting Volumio Volume from Spotify: 61 Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: VolumeController::SetAlsaVolume61 Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:54:58 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:58Z" level=debug msg="update volume to 34407/65535" Jan 16 22:54:58 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:58Z" level=debug msg="put connect state because VOLUME_CHANGED" Jan 16 22:54:58 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:54:58Z" level=trace msg="emitting websocket event: volume" Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: received: {"type":"volume","data":{"value":53,"max":100}} Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: SPOTIFY: RECEIVED SPOTIFY VOLUME 53 Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: Setting Volumio Volume from Spotify: 53 Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: VolumeController::SetAlsaVolume53 Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreStateMachine::pushState Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: CoreCommandRouter::volumioPushState Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output update for this device Jan 16 22:54:58 volumio-luisterruimte-nederhorst volumio[1236]: info: MRS: Pushing multiroomSync output Jan 16 22:55:01 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:55:01Z" level=debug msg="fetched chunk 4/47, size: 524288" uri="spotify:track:21cp8L9Pei4AgysZVihjSv" Jan 16 22:55:14 volumio-luisterruimte-nederhorst go-librespot[3106]: time="2025-01-16T22:55:14Z" level=debug msg="fetched chunk 5/47, size: 524288" uri="spotify:track:21cp8L9Pei4AgysZVihjSv" Jan 16 22:55:17 volumio-luisterruimte-nederhorst volumio[1236]: info: [1737068117387] [80s80s] Pushing the next song state Billy Idol - Eyes Without a Face and getting next track. Jan 16 22:55:17 volumio-luisterruimte-nederhorst volumio[1236]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 16 22:55:17 volumio-luisterruimte-nederhorst volumio[1236]: TypeError: Cannot set property 'name' of undefined Jan 16 22:55:17 volumio-luisterruimte-nederhorst volumio[1236]: at Controller80s80s.pushSongState (/data/plugins/music_service/80s80s/index.js:565:20) Jan 16 22:55:17 volumio-luisterruimte-nederhorst volumio[1236]: at Controller80s80s.playNextTrack (/data/plugins/music_service/80s80s/index.js:665:34) Jan 16 22:55:17 volumio-luisterruimte-nederhorst volumio[1236]: at NanoTimer.setTimeout (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:343:9) Jan 16 22:55:17 volumio-luisterruimte-nederhorst volumio[1236]: at Immediate. (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:327:66) Jan 16 22:55:17 volumio-luisterruimte-nederhorst volumio[1236]: at processImmediate (internal/timers.js:464:21) Jan 16 22:55:17 volumio-luisterruimte-nederhorst volumio[1236]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 16 22:55:17 volumio-luisterruimte-nederhorst sudo[6312]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-01-16 22:54 Jan 16 22:55:17 volumio-luisterruimte-nederhorst sudo[6312]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:11:38 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="932fc3546f7cc8faa2b4d349036752dd"