-- Logs begin at Fri 2024-11-22 20:35:11 CET, end at Mon 2024-11-25 07:39:59 CET. -- Nov 25 07:38:06 teenieboombox go-librespot[1495]: time="2024-11-25T07:38:06+01:00" level=debug msg="fetched chunk 5/13, size: 524288" uri="spotify:track:7ztK7bcnIst4Dy0lTu37S6" Nov 25 07:38:12 teenieboombox systemd[1]: Started Checkmk agent updater. Nov 25 07:38:12 teenieboombox systemd[1]: cmk-update-agent.service: Succeeded. Nov 25 07:38:17 teenieboombox systemd[1]: Started Checkmk agent (10.10.10.2:39296). Nov 25 07:38:19 teenieboombox go-librespot[1495]: time="2024-11-25T07:38:19+01:00" level=debug msg="fetched chunk 6/13, size: 524288" uri="spotify:track:7ztK7bcnIst4Dy0lTu37S6" Nov 25 07:38:20 teenieboombox systemd[1]: check-mk-agent@4545-10.10.40.102:6556-10.10.10.2:39296.service: Succeeded. Nov 25 07:38:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:38:31+01:00" level=debug msg="fetched chunk 7/13, size: 524288" uri="spotify:track:7ztK7bcnIst4Dy0lTu37S6" Nov 25 07:38:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:38:43+01:00" level=debug msg="fetched chunk 8/13, size: 524288" uri="spotify:track:7ztK7bcnIst4Dy0lTu37S6" Nov 25 07:38:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:38:55+01:00" level=debug msg="fetched chunk 9/13, size: 524288" uri="spotify:track:7ztK7bcnIst4Dy0lTu37S6" Nov 25 07:39:07 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:07+01:00" level=debug msg="fetched chunk 10/13, size: 524288" uri="spotify:track:7ztK7bcnIst4Dy0lTu37S6" Nov 25 07:39:12 teenieboombox systemd[1]: Started Checkmk agent updater. Nov 25 07:39:13 teenieboombox systemd[1]: cmk-update-agent.service: Succeeded. Nov 25 07:39:20 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:20+01:00" level=debug msg="fetched chunk 11/13, size: 524288" uri="spotify:track:7ztK7bcnIst4Dy0lTu37S6" Nov 25 07:39:20 teenieboombox systemd[1]: Started Checkmk agent (10.10.10.2:41738). Nov 25 07:39:23 teenieboombox systemd[1]: check-mk-agent@4546-10.10.40.102:6556-10.10.10.2:41738.service: Succeeded. Nov 25 07:39:31 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioNext Nov 25 07:39:31 teenieboombox volumio[1025]: info: CoreStateMachine::next Nov 25 07:39:31 teenieboombox volumio[1025]: info: CoreStateMachine::stop Nov 25 07:39:31 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:31 teenieboombox volumio[1025]: info: CoreStateMachine::stPlaybackTimer Nov 25 07:39:31 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:31 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:31 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:31 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 28 Nov 25 07:39:31 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:31 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:31 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:31 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:31 teenieboombox volumio[1025]: info: CoreStateMachine::serviceStop Nov 25 07:39:31 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 28 Nov 25 07:39:31 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceStop Nov 25 07:39:31 teenieboombox volumio[1025]: info: Spotify Stop Nov 25 07:39:31 teenieboombox volumio[1025]: SPOTIFY: SPOTIFY STOP Nov 25 07:39:31 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","position":28,"title":"XY","artist":"AK AUSSERKONTROLLE","album":"XY","albumart":"https://i.scdn.co/image/ab67616d0000b27396360b0cbff9b82e7126fd18","uri":"spotify:track:7ztK7bcnIst4Dy0lTu37S6","trackType":"spotify","codec":"ogg","seek":250,"duration":167,"samplerate":"320 kbps","bitdepth":"16 bit","random":true,"repeat":false,"repeatSingle":false,"consume":false,"volume":46,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Nov 25 07:39:31 teenieboombox volumio[1025]: info: Sending Spotify command to local API: /player/pause Nov 25 07:39:31 teenieboombox volumio[1025]: info: CoreStateMachine::play index undefined Nov 25 07:39:31 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:31 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 42 Nov 25 07:39:31 teenieboombox volumio[1025]: info: CoreStateMachine::startPlaybackTimer Nov 25 07:39:31 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 42 Nov 25 07:39:31 teenieboombox volumio[1025]: info: [1732516771488] ControllerSpotify::clearAddPlayTrack Nov 25 07:39:31 teenieboombox volumio[1025]: info: Sending Spotify command with payload to local API: /player/play Nov 25 07:39:31 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:31 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:31 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:31+01:00" level=debug msg="pause track at 111922ms" Nov 25 07:39:31 teenieboombox volumio[1025]: info: touch_display: Setting screensaver timeout to 120 seconds. Nov 25 07:39:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:31+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:31+01:00" level=debug msg="resolved context of track" uri="spotify:track:1K4snL5lbTUfSDkjOLUh93" Nov 25 07:39:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:31+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1K4snL5lbTUfSDkjOLUh93" Nov 25 07:39:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:31+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1K4snL5lbTUfSDkjOLUh93" Nov 25 07:39:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:31+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:31+01:00" level=trace msg="emitting websocket event: will_play" Nov 25 07:39:31 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1K4snL5lbTUfSDkjOLUh93","play_origin":"go-librespot"}} Nov 25 07:39:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:31+01:00" level=debug msg="selected format OGG_VORBIS_320 (3e36bb7c07bd5dfa22678ced7ba8dbaff078d2b8)" uri="spotify:track:1K4snL5lbTUfSDkjOLUh93" Nov 25 07:39:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:31+01:00" level=debug msg="requested aes key for file 3e36bb7c07bd5dfa22678ced7ba8dbaff078d2b8, gid: 1K4snL5lbTUfSDkjOLUh93" Nov 25 07:39:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:31+01:00" level=debug msg="fetched first chunk of 16, total size is 8209380 bytes" uri="spotify:track:1K4snL5lbTUfSDkjOLUh93" Nov 25 07:39:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:31+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:1K4snL5lbTUfSDkjOLUh93" Nov 25 07:39:31 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 25 07:39:31 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 25 07:39:31 teenieboombox volumio[1025]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 25 07:39:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:31+01:00" level=info msg="loaded track \"WEIß NICHT\" (paused: false, position: 0ms, duration: 204117ms, prefetched: false)" uri="spotify:track:1K4snL5lbTUfSDkjOLUh93" Nov 25 07:39:31 teenieboombox volumio[1025]: info: FusionDsp - Effects disabled Nov 25 07:39:31 teenieboombox volumio[1025]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 25 07:39:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:31+01:00" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:1K4snL5lbTUfSDkjOLUh93" Nov 25 07:39:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:31+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:31+01:00" level=trace msg="scheduling prefetch in 174s" Nov 25 07:39:31 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:31+01:00" level=trace msg="emitting websocket event: metadata" Nov 25 07:39:31 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1K4snL5lbTUfSDkjOLUh93","name":"WEIß NICHT","artist_names":["EMES"],"album_name":"MONEY CHANGES BREDRINS","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02b61ca513f84b1158b880a72c","position":0,"duration":204117,"release_date":"year:2024 month:6 day:6","track_number":8,"disc_number":1}} Nov 25 07:39:32 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:32+01:00" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:1K4snL5lbTUfSDkjOLUh93" Nov 25 07:39:32 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:32+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:32 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:32+01:00" level=trace msg="emitting websocket event: paused" Nov 25 07:39:32 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:1K4snL5lbTUfSDkjOLUh93","play_origin":"go-librespot"}} Nov 25 07:39:32 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:32 teenieboombox volumio[1025]: SPOTIFY: {"status":"pause","service":"spop","title":"WEIß NICHT","artist":"EMES","album":"MONEY CHANGES BREDRINS","albumart":"https://i.scdn.co/image/ab67616d00001e02b61ca513f84b1158b880a72c","uri":"spotify:track:1K4snL5lbTUfSDkjOLUh93","trackType":"spotify","seek":0,"duration":204,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:32 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 42 Nov 25 07:39:32 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"WEIß NICHT","artist":"EMES","album":"MONEY CHANGES BREDRINS","albumart":"https://i.scdn.co/image/ab67616d00001e02b61ca513f84b1158b880a72c","uri":"spotify:track:1K4snL5lbTUfSDkjOLUh93","trackType":"spotify","seek":0,"duration":204,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:32 teenieboombox volumio[1025]: verbose: CURRENT POSITION 42 Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService pause Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:32 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 42 Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:32 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:32 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:32 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:32 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:32+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:32 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:32+01:00" level=trace msg="emitting websocket event: playing" Nov 25 07:39:32 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:32+01:00" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:1K4snL5lbTUfSDkjOLUh93" Nov 25 07:39:32 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1K4snL5lbTUfSDkjOLUh93","play_origin":"go-librespot"}} Nov 25 07:39:32 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:32 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"WEIß NICHT","artist":"EMES","album":"MONEY CHANGES BREDRINS","albumart":"https://i.scdn.co/image/ab67616d00001e02b61ca513f84b1158b880a72c","uri":"spotify:track:1K4snL5lbTUfSDkjOLUh93","trackType":"spotify","seek":0,"duration":204,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:32 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 42 Nov 25 07:39:32 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"WEIß NICHT","artist":"EMES","album":"MONEY CHANGES BREDRINS","albumart":"https://i.scdn.co/image/ab67616d00001e02b61ca513f84b1158b880a72c","uri":"spotify:track:1K4snL5lbTUfSDkjOLUh93","trackType":"spotify","seek":0,"duration":204,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:32 teenieboombox volumio[1025]: verbose: CURRENT POSITION 42 Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:32 teenieboombox volumio[1025]: info: camilladsp spawned new process with pid 29938, instance 1, run: true Nov 25 07:39:32 teenieboombox kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 25 07:39:32 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:32 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"WEIß NICHT","artist":"EMES","album":"MONEY CHANGES BREDRINS","albumart":"https://i.scdn.co/image/ab67616d00001e02b61ca513f84b1158b880a72c","uri":"spotify:track:1K4snL5lbTUfSDkjOLUh93","trackType":"spotify","seek":0,"duration":204,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:32 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 42 Nov 25 07:39:32 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"WEIß NICHT","artist":"EMES","album":"MONEY CHANGES BREDRINS","albumart":"https://i.scdn.co/image/ab67616d00001e02b61ca513f84b1158b880a72c","uri":"spotify:track:1K4snL5lbTUfSDkjOLUh93","trackType":"spotify","seek":0,"duration":204,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:32 teenieboombox volumio[1025]: verbose: CURRENT POSITION 42 Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus play Nov 25 07:39:32 teenieboombox volumio[1025]: info: Received an update from plugin. extracting info from payload Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:32 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 42 Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:32 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:32 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:32 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 42 Nov 25 07:39:32 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:32 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:32 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:32 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:32 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioNext Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreStateMachine::next Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreStateMachine::stop Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreStateMachine::stPlaybackTimer Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:35 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:35 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 42 Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:35 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:35 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreStateMachine::serviceStop Nov 25 07:39:35 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 42 Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceStop Nov 25 07:39:35 teenieboombox volumio[1025]: info: Spotify Stop Nov 25 07:39:35 teenieboombox volumio[1025]: SPOTIFY: SPOTIFY STOP Nov 25 07:39:35 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","position":42,"title":"WEIß NICHT","artist":"EMES","album":"MONEY CHANGES BREDRINS","albumart":"https://i.scdn.co/image/ab67616d0000b273b61ca513f84b1158b880a72c","uri":"spotify:track:1K4snL5lbTUfSDkjOLUh93","trackType":"spotify","codec":"ogg","seek":0,"duration":204,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":false,"repeatSingle":false,"consume":false,"volume":46,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Nov 25 07:39:35 teenieboombox volumio[1025]: info: Sending Spotify command to local API: /player/pause Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreStateMachine::play index undefined Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:35 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 9 Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreStateMachine::startPlaybackTimer Nov 25 07:39:35 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 9 Nov 25 07:39:35 teenieboombox volumio[1025]: info: [1732516775081] ControllerSpotify::clearAddPlayTrack Nov 25 07:39:35 teenieboombox volumio[1025]: info: Sending Spotify command with payload to local API: /player/play Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:35 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:35 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:35 teenieboombox volumio[1025]: info: touch_display: Setting screensaver timeout to 120 seconds. Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=debug msg="pause track at 3730ms" Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=trace msg="emitting websocket event: paused" Nov 25 07:39:35 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:1K4snL5lbTUfSDkjOLUh93","play_origin":"go-librespot"}} Nov 25 07:39:35 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:35 teenieboombox volumio[1025]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":1000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:35 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 9 Nov 25 07:39:35 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":1000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:35 teenieboombox volumio[1025]: verbose: CURRENT POSITION 9 Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService pause Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:35 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 9 Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:35 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:35 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:35 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=debug msg="resolved context of track" uri="spotify:track:7xaqxUl08zOg0YNUHokQpq" Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:7xaqxUl08zOg0YNUHokQpq" Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:7xaqxUl08zOg0YNUHokQpq" Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=trace msg="emitting websocket event: will_play" Nov 25 07:39:35 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7xaqxUl08zOg0YNUHokQpq","play_origin":"go-librespot"}} Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=debug msg="selected format OGG_VORBIS_320 (30e9c3ab6da476a71b5282ed49ae24a60ff533ea)" uri="spotify:track:7xaqxUl08zOg0YNUHokQpq" Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=debug msg="requested aes key for file 30e9c3ab6da476a71b5282ed49ae24a60ff533ea, gid: 7xaqxUl08zOg0YNUHokQpq" Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=debug msg="fetched first chunk of 13, total size is 6566368 bytes" uri="spotify:track:7xaqxUl08zOg0YNUHokQpq" Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:7xaqxUl08zOg0YNUHokQpq" Nov 25 07:39:35 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 25 07:39:35 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 25 07:39:35 teenieboombox volumio[1025]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=info msg="loaded track \"Sehnsucht\" (paused: false, position: 0ms, duration: 152826ms, prefetched: false)" uri="spotify:track:7xaqxUl08zOg0YNUHokQpq" Nov 25 07:39:35 teenieboombox volumio[1025]: info: FusionDsp - Effects disabled Nov 25 07:39:35 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 25 07:39:35 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 25 07:39:35 teenieboombox volumio[1025]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 25 07:39:35 teenieboombox volumio[1025]: info: FusionDsp - Effects disabled Nov 25 07:39:35 teenieboombox volumio[1025]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 25 07:39:35 teenieboombox volumio[1025]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=debug msg="fetched chunk 1/12, size: 524288" uri="spotify:track:7xaqxUl08zOg0YNUHokQpq" Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=trace msg="scheduling prefetch in 123s" Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=trace msg="emitting websocket event: metadata" Nov 25 07:39:35 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7xaqxUl08zOg0YNUHokQpq","name":"Sehnsucht","artist_names":["Miksu / Macloud","t-low"],"album_name":"Sehnsucht","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0208149e5134b5001df415e38b","position":0,"duration":152826,"release_date":"year:2022 month:3 day:4","track_number":1,"disc_number":1}} Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=debug msg="fetched chunk 3/12, size: 524288" uri="spotify:track:7xaqxUl08zOg0YNUHokQpq" Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=trace msg="emitting websocket event: playing" Nov 25 07:39:35 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7xaqxUl08zOg0YNUHokQpq","play_origin":"go-librespot"}} Nov 25 07:39:35 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:35 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"Sehnsucht","artist":"Miksu / Macloud, t-low","album":"Sehnsucht","albumart":"https://i.scdn.co/image/ab67616d00001e0208149e5134b5001df415e38b","uri":"spotify:track:7xaqxUl08zOg0YNUHokQpq","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:35 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 9 Nov 25 07:39:35 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Sehnsucht","artist":"Miksu / Macloud, t-low","album":"Sehnsucht","albumart":"https://i.scdn.co/image/ab67616d00001e0208149e5134b5001df415e38b","uri":"spotify:track:7xaqxUl08zOg0YNUHokQpq","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:35 teenieboombox volumio[1025]: verbose: CURRENT POSITION 9 Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:35 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:35 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:35+01:00" level=debug msg="fetched chunk 2/12, size: 524288" uri="spotify:track:7xaqxUl08zOg0YNUHokQpq" Nov 25 07:39:36 teenieboombox volumio[1025]: info: camilladsp spawned new process with pid 29964, instance 1, run: true Nov 25 07:39:36 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:36 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"Sehnsucht","artist":"Miksu / Macloud, t-low","album":"Sehnsucht","albumart":"https://i.scdn.co/image/ab67616d00001e0208149e5134b5001df415e38b","uri":"spotify:track:7xaqxUl08zOg0YNUHokQpq","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:36 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:36 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 9 Nov 25 07:39:36 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Sehnsucht","artist":"Miksu / Macloud, t-low","album":"Sehnsucht","albumart":"https://i.scdn.co/image/ab67616d00001e0208149e5134b5001df415e38b","uri":"spotify:track:7xaqxUl08zOg0YNUHokQpq","trackType":"spotify","seek":0,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:36 teenieboombox volumio[1025]: verbose: CURRENT POSITION 9 Nov 25 07:39:36 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:36 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus play Nov 25 07:39:36 teenieboombox volumio[1025]: info: Received an update from plugin. extracting info from payload Nov 25 07:39:36 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:36 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 9 Nov 25 07:39:36 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:36 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:36 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:36 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:36 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:36 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 9 Nov 25 07:39:36 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:36 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:36 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:36 teenieboombox kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 25 07:39:36 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:36 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPause Nov 25 07:39:36 teenieboombox volumio[1025]: info: CoreStateMachine::pause Nov 25 07:39:36 teenieboombox volumio[1025]: info: CoreStateMachine::stPlaybackTimer Nov 25 07:39:36 teenieboombox volumio[1025]: info: CoreStateMachine::servicePause Nov 25 07:39:36 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 9 Nov 25 07:39:36 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePause Nov 25 07:39:36 teenieboombox volumio[1025]: info: Spotify Received pause Nov 25 07:39:36 teenieboombox volumio[1025]: SPOTIFY: SPOTIFY PAUSE Nov 25 07:39:36 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","position":9,"title":"Sehnsucht","artist":"Miksu / Macloud","album":"Sehnsucht","albumart":"https://i.scdn.co/image/ab67616d0000b27308149e5134b5001df415e38b","uri":"spotify:track:7xaqxUl08zOg0YNUHokQpq","trackType":"spotify","codec":"ogg","seek":0,"duration":152,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":false,"repeatSingle":false,"consume":false,"volume":46,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Nov 25 07:39:36 teenieboombox volumio[1025]: info: Sending Spotify command to local API: /player/pause Nov 25 07:39:36 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:36+01:00" level=debug msg="pause track at 1796ms" Nov 25 07:39:36 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:36+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:37 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:37+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:37 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:37+01:00" level=trace msg="emitting websocket event: paused" Nov 25 07:39:37 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:7xaqxUl08zOg0YNUHokQpq","play_origin":"go-librespot"}} Nov 25 07:39:37 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:37 teenieboombox volumio[1025]: SPOTIFY: {"status":"pause","service":"spop","title":"Sehnsucht","artist":"Miksu / Macloud, t-low","album":"Sehnsucht","albumart":"https://i.scdn.co/image/ab67616d00001e0208149e5134b5001df415e38b","uri":"spotify:track:7xaqxUl08zOg0YNUHokQpq","trackType":"spotify","seek":1000,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:37 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:37 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 9 Nov 25 07:39:37 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Sehnsucht","artist":"Miksu / Macloud, t-low","album":"Sehnsucht","albumart":"https://i.scdn.co/image/ab67616d00001e0208149e5134b5001df415e38b","uri":"spotify:track:7xaqxUl08zOg0YNUHokQpq","trackType":"spotify","seek":1000,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:37 teenieboombox volumio[1025]: verbose: CURRENT POSITION 9 Nov 25 07:39:37 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService pause Nov 25 07:39:37 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus pause Nov 25 07:39:37 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:37 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 9 Nov 25 07:39:37 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:37 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:37 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:37 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:37 teenieboombox volumio[1025]: info: CoreStateMachine::stPlaybackTimer Nov 25 07:39:37 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:37 teenieboombox volumio[1025]: info: touch_display: Setting screensaver timeout to 120 seconds. Nov 25 07:39:37 teenieboombox volumio[1025]: info: camilladsp spawned new process with pid 29974, instance 1, run: true Nov 25 07:39:37 teenieboombox kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioNext Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::next Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::stop Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:40 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::stPlaybackTimer Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:40 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 9 Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:40 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:40 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::serviceStop Nov 25 07:39:40 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 9 Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceStop Nov 25 07:39:40 teenieboombox volumio[1025]: info: Spotify Stop Nov 25 07:39:40 teenieboombox volumio[1025]: SPOTIFY: SPOTIFY STOP Nov 25 07:39:40 teenieboombox volumio[1025]: SPOTIFY: {"status":"pause","position":9,"title":"Sehnsucht","artist":"Miksu / Macloud","album":"Sehnsucht","albumart":"https://i.scdn.co/image/ab67616d0000b27308149e5134b5001df415e38b","uri":"spotify:track:7xaqxUl08zOg0YNUHokQpq","trackType":"spotify","codec":"ogg","seek":1571,"duration":152,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":false,"repeatSingle":false,"consume":false,"volume":46,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Nov 25 07:39:40 teenieboombox volumio[1025]: info: Sending Spotify command to local API: /player/pause Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::play index undefined Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:40 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 16 Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::startPlaybackTimer Nov 25 07:39:40 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 16 Nov 25 07:39:40 teenieboombox volumio[1025]: info: [1732516780079] ControllerSpotify::clearAddPlayTrack Nov 25 07:39:40 teenieboombox volumio[1025]: info: Sending Spotify command with payload to local API: /player/play Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:40 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:40 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=debug msg="pause track at 2751ms" Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=trace msg="emitting websocket event: paused" Nov 25 07:39:40 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:7xaqxUl08zOg0YNUHokQpq","play_origin":"go-librespot"}} Nov 25 07:39:40 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:40 teenieboombox volumio[1025]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:40 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 16 Nov 25 07:39:40 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:40 teenieboombox volumio[1025]: verbose: CURRENT POSITION 16 Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService pause Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:40 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 16 Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:40 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:40 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:40 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=debug msg="resolved context of track" uri="spotify:track:2LtD83L2gaZxvAqTaNw7EO" Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:2LtD83L2gaZxvAqTaNw7EO" Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2LtD83L2gaZxvAqTaNw7EO" Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=trace msg="emitting websocket event: will_play" Nov 25 07:39:40 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2LtD83L2gaZxvAqTaNw7EO","play_origin":"go-librespot"}} Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=debug msg="selected format OGG_VORBIS_320 (7e5161c5b486be3fd978fc1a8f053ed9d729c66e)" uri="spotify:track:2LtD83L2gaZxvAqTaNw7EO" Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=debug msg="requested aes key for file 7e5161c5b486be3fd978fc1a8f053ed9d729c66e, gid: 2LtD83L2gaZxvAqTaNw7EO" Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=debug msg="fetched first chunk of 16, total size is 8216716 bytes" uri="spotify:track:2LtD83L2gaZxvAqTaNw7EO" Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:2LtD83L2gaZxvAqTaNw7EO" Nov 25 07:39:40 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate, raw: Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=info msg="loaded track \"RADW\" (paused: false, position: 0ms, duration: 197133ms, prefetched: false)" uri="spotify:track:2LtD83L2gaZxvAqTaNw7EO" Nov 25 07:39:40 teenieboombox volumio[1025]: error: FusionDsp - invalid sample rate Nov 25 07:39:40 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 25 07:39:40 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 25 07:39:40 teenieboombox volumio[1025]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 25 07:39:40 teenieboombox volumio[1025]: info: FusionDsp - Effects disabled Nov 25 07:39:40 teenieboombox volumio[1025]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:2LtD83L2gaZxvAqTaNw7EO" Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=trace msg="scheduling prefetch in 167s" Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=trace msg="emitting websocket event: metadata" Nov 25 07:39:40 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2LtD83L2gaZxvAqTaNw7EO","name":"RADW","artist_names":["Haftbefehl","Bazzazian"],"album_name":"Das weisse Album","album_cover_url":"https://i.scdn.co/image/ab67616d00001e025f55b85b8a266877a6e1bf64","position":0,"duration":197133,"release_date":"year:2020 month:6 day:4","track_number":6,"disc_number":1}} Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:2LtD83L2gaZxvAqTaNw7EO" Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=trace msg="emitting websocket event: playing" Nov 25 07:39:40 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:2LtD83L2gaZxvAqTaNw7EO","play_origin":"go-librespot"}} Nov 25 07:39:40 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:40 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"RADW","artist":"Haftbefehl, Bazzazian","album":"Das weisse Album","albumart":"https://i.scdn.co/image/ab67616d00001e025f55b85b8a266877a6e1bf64","uri":"spotify:track:2LtD83L2gaZxvAqTaNw7EO","trackType":"spotify","seek":0,"duration":197,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:40 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 16 Nov 25 07:39:40 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"RADW","artist":"Haftbefehl, Bazzazian","album":"Das weisse Album","albumart":"https://i.scdn.co/image/ab67616d00001e025f55b85b8a266877a6e1bf64","uri":"spotify:track:2LtD83L2gaZxvAqTaNw7EO","trackType":"spotify","seek":0,"duration":197,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:40 teenieboombox volumio[1025]: verbose: CURRENT POSITION 16 Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:40 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:40+01:00" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:2LtD83L2gaZxvAqTaNw7EO" Nov 25 07:39:40 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:40 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"RADW","artist":"Haftbefehl, Bazzazian","album":"Das weisse Album","albumart":"https://i.scdn.co/image/ab67616d00001e025f55b85b8a266877a6e1bf64","uri":"spotify:track:2LtD83L2gaZxvAqTaNw7EO","trackType":"spotify","seek":0,"duration":197,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:40 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 16 Nov 25 07:39:40 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"RADW","artist":"Haftbefehl, Bazzazian","album":"Das weisse Album","albumart":"https://i.scdn.co/image/ab67616d00001e025f55b85b8a266877a6e1bf64","uri":"spotify:track:2LtD83L2gaZxvAqTaNw7EO","trackType":"spotify","seek":0,"duration":197,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:40 teenieboombox volumio[1025]: verbose: CURRENT POSITION 16 Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus play Nov 25 07:39:40 teenieboombox volumio[1025]: info: Received an update from plugin. extracting info from payload Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:40 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 16 Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:40 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:40 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:40 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 16 Nov 25 07:39:40 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:40 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:40 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:40 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioNext Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreStateMachine::next Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreStateMachine::stop Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreStateMachine::stPlaybackTimer Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:41 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:41 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 16 Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:41 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:41 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreStateMachine::serviceStop Nov 25 07:39:41 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 16 Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceStop Nov 25 07:39:41 teenieboombox volumio[1025]: info: Spotify Stop Nov 25 07:39:41 teenieboombox volumio[1025]: SPOTIFY: SPOTIFY STOP Nov 25 07:39:41 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","position":16,"title":"RADW","artist":"Haftbefehl","album":"Das weisse Album","albumart":"https://i.scdn.co/image/ab67616d0000b2735f55b85b8a266877a6e1bf64","uri":"spotify:track:2LtD83L2gaZxvAqTaNw7EO","trackType":"spotify","codec":"ogg","seek":0,"duration":197,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":false,"repeatSingle":false,"consume":false,"volume":46,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Nov 25 07:39:41 teenieboombox volumio[1025]: info: Sending Spotify command to local API: /player/pause Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreStateMachine::play index undefined Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:41 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 14 Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreStateMachine::startPlaybackTimer Nov 25 07:39:41 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 14 Nov 25 07:39:41 teenieboombox volumio[1025]: info: [1732516781451] ControllerSpotify::clearAddPlayTrack Nov 25 07:39:41 teenieboombox volumio[1025]: info: Sending Spotify command with payload to local API: /player/play Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:41 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:41 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:41 teenieboombox volumio[1025]: info: touch_display: Setting screensaver timeout to 120 seconds. Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=debug msg="pause track at 1913ms" Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=trace msg="emitting websocket event: paused" Nov 25 07:39:41 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2LtD83L2gaZxvAqTaNw7EO","play_origin":"go-librespot"}} Nov 25 07:39:41 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:41 teenieboombox volumio[1025]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:41 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 14 Nov 25 07:39:41 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:41 teenieboombox volumio[1025]: verbose: CURRENT POSITION 14 Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService pause Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:41 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 14 Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:41 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:41 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:41 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=debug msg="resolved context of track" uri="spotify:track:7vkq044gRCCrEhThIHvbI7" Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:7vkq044gRCCrEhThIHvbI7" Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:7vkq044gRCCrEhThIHvbI7" Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=trace msg="emitting websocket event: will_play" Nov 25 07:39:41 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7vkq044gRCCrEhThIHvbI7","play_origin":"go-librespot"}} Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=debug msg="selected format OGG_VORBIS_320 (d02e0aecfb87788364bd3f5bf63b42de023c6319)" uri="spotify:track:7vkq044gRCCrEhThIHvbI7" Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=debug msg="requested aes key for file d02e0aecfb87788364bd3f5bf63b42de023c6319, gid: 7vkq044gRCCrEhThIHvbI7" Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=debug msg="fetched first chunk of 12, total size is 6019480 bytes" uri="spotify:track:7vkq044gRCCrEhThIHvbI7" Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:7vkq044gRCCrEhThIHvbI7" Nov 25 07:39:41 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 25 07:39:41 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 25 07:39:41 teenieboombox volumio[1025]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=info msg="loaded track \"Tourlife.mp3\" (paused: false, position: 0ms, duration: 134093ms, prefetched: false)" uri="spotify:track:7vkq044gRCCrEhThIHvbI7" Nov 25 07:39:41 teenieboombox volumio[1025]: info: FusionDsp - Effects disabled Nov 25 07:39:41 teenieboombox volumio[1025]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=debug msg="fetched chunk 1/11, size: 524288" uri="spotify:track:7vkq044gRCCrEhThIHvbI7" Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=trace msg="scheduling prefetch in 104s" Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=trace msg="emitting websocket event: metadata" Nov 25 07:39:41 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7vkq044gRCCrEhThIHvbI7","name":"Tourlife.mp3","artist_names":["Pashanim"],"album_name":"Himmel über Berlin","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02fa2f0c9e719ca71f2686ddf3","position":0,"duration":134093,"release_date":"year:2022 month:9 day:28","track_number":5,"disc_number":1}} Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=debug msg="fetched chunk 2/11, size: 524288" uri="spotify:track:7vkq044gRCCrEhThIHvbI7" Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:41 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:41+01:00" level=trace msg="emitting websocket event: playing" Nov 25 07:39:41 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7vkq044gRCCrEhThIHvbI7","play_origin":"go-librespot"}} Nov 25 07:39:41 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:41 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"Tourlife.mp3","artist":"Pashanim","album":"Himmel über Berlin","albumart":"https://i.scdn.co/image/ab67616d00001e02fa2f0c9e719ca71f2686ddf3","uri":"spotify:track:7vkq044gRCCrEhThIHvbI7","trackType":"spotify","seek":0,"duration":134,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:41 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 14 Nov 25 07:39:41 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Tourlife.mp3","artist":"Pashanim","album":"Himmel über Berlin","albumart":"https://i.scdn.co/image/ab67616d00001e02fa2f0c9e719ca71f2686ddf3","uri":"spotify:track:7vkq044gRCCrEhThIHvbI7","trackType":"spotify","seek":0,"duration":134,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:41 teenieboombox volumio[1025]: verbose: CURRENT POSITION 14 Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:41 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:42 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:42+01:00" level=debug msg="fetched chunk 3/11, size: 524288" uri="spotify:track:7vkq044gRCCrEhThIHvbI7" Nov 25 07:39:42 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:42 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"Tourlife.mp3","artist":"Pashanim","album":"Himmel über Berlin","albumart":"https://i.scdn.co/image/ab67616d00001e02fa2f0c9e719ca71f2686ddf3","uri":"spotify:track:7vkq044gRCCrEhThIHvbI7","trackType":"spotify","seek":0,"duration":134,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:42 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:42 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 14 Nov 25 07:39:42 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Tourlife.mp3","artist":"Pashanim","album":"Himmel über Berlin","albumart":"https://i.scdn.co/image/ab67616d00001e02fa2f0c9e719ca71f2686ddf3","uri":"spotify:track:7vkq044gRCCrEhThIHvbI7","trackType":"spotify","seek":0,"duration":134,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:42 teenieboombox volumio[1025]: verbose: CURRENT POSITION 14 Nov 25 07:39:42 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:42 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus play Nov 25 07:39:42 teenieboombox volumio[1025]: info: Received an update from plugin. extracting info from payload Nov 25 07:39:42 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:42 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 14 Nov 25 07:39:42 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:42 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:42 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:42 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:42 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:42 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 14 Nov 25 07:39:42 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:42 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:42 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:42 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:42 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:42 teenieboombox volumio[1025]: info: camilladsp spawned new process with pid 29991, instance 1, run: true Nov 25 07:39:42 teenieboombox kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioNext Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreStateMachine::next Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreStateMachine::stop Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreStateMachine::stPlaybackTimer Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:43 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:43 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 14 Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:43 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:43 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreStateMachine::serviceStop Nov 25 07:39:43 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 14 Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceStop Nov 25 07:39:43 teenieboombox volumio[1025]: info: Spotify Stop Nov 25 07:39:43 teenieboombox volumio[1025]: SPOTIFY: SPOTIFY STOP Nov 25 07:39:43 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","position":14,"title":"Tourlife.mp3","artist":"Pashanim","album":"Himmel über Berlin","albumart":"https://i.scdn.co/image/ab67616d0000b273fa2f0c9e719ca71f2686ddf3","uri":"spotify:track:7vkq044gRCCrEhThIHvbI7","trackType":"spotify","codec":"ogg","seek":0,"duration":134,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":false,"repeatSingle":false,"consume":false,"volume":46,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Nov 25 07:39:43 teenieboombox volumio[1025]: info: Sending Spotify command to local API: /player/pause Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreStateMachine::play index undefined Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:43 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 39 Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreStateMachine::startPlaybackTimer Nov 25 07:39:43 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 39 Nov 25 07:39:43 teenieboombox volumio[1025]: info: [1732516783262] ControllerSpotify::clearAddPlayTrack Nov 25 07:39:43 teenieboombox volumio[1025]: info: Sending Spotify command with payload to local API: /player/play Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:43 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:43 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:43 teenieboombox volumio[1025]: info: touch_display: Setting screensaver timeout to 120 seconds. Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=debug msg="pause track at 1907ms" Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=debug msg="resolved context of track" uri="spotify:track:7AuMPJMHY3TYeZEZsEy0CF" Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:7AuMPJMHY3TYeZEZsEy0CF" Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:7AuMPJMHY3TYeZEZsEy0CF" Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=trace msg="emitting websocket event: will_play" Nov 25 07:39:43 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7AuMPJMHY3TYeZEZsEy0CF","play_origin":"go-librespot"}} Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=debug msg="selected format OGG_VORBIS_320 (e61a2e50e15d674f863b26deec69e9b5404892a8)" uri="spotify:track:7AuMPJMHY3TYeZEZsEy0CF" Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=debug msg="requested aes key for file e61a2e50e15d674f863b26deec69e9b5404892a8, gid: 7AuMPJMHY3TYeZEZsEy0CF" Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=debug msg="fetched first chunk of 14, total size is 7081684 bytes" uri="spotify:track:7AuMPJMHY3TYeZEZsEy0CF" Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:7AuMPJMHY3TYeZEZsEy0CF" Nov 25 07:39:43 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate, raw: Nov 25 07:39:43 teenieboombox volumio[1025]: error: FusionDsp - invalid sample rate Nov 25 07:39:43 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 25 07:39:43 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 25 07:39:43 teenieboombox volumio[1025]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 25 07:39:43 teenieboombox volumio[1025]: info: FusionDsp - Effects disabled Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=info msg="loaded track \"mailbox (feat. Hava)\" (paused: false, position: 0ms, duration: 174413ms, prefetched: false)" uri="spotify:track:7AuMPJMHY3TYeZEZsEy0CF" Nov 25 07:39:43 teenieboombox volumio[1025]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=trace msg="scheduling prefetch in 144s" Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=trace msg="emitting websocket event: metadata" Nov 25 07:39:43 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7AuMPJMHY3TYeZEZsEy0CF","name":"mailbox (feat. Hava)","artist_names":["Dardan","Hava"],"album_name":"MISTER DARDY","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0228d825673365816b020f1bfa","position":0,"duration":174413,"release_date":"year:2021 month:2 day:4","track_number":2,"disc_number":1}} Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=debug msg="fetched chunk 2/13, size: 524288" uri="spotify:track:7AuMPJMHY3TYeZEZsEy0CF" Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=debug msg="fetched chunk 1/13, size: 524288" uri="spotify:track:7AuMPJMHY3TYeZEZsEy0CF" Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=error msg="failed put state after update" error="put state request failed with status 429: Too many requests for user" Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=trace msg="emitting websocket event: paused" Nov 25 07:39:43 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:7AuMPJMHY3TYeZEZsEy0CF","play_origin":"go-librespot"}} Nov 25 07:39:43 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:43 teenieboombox volumio[1025]: SPOTIFY: {"status":"pause","service":"spop","title":"mailbox (feat. Hava)","artist":"Dardan, Hava","album":"MISTER DARDY","albumart":"https://i.scdn.co/image/ab67616d00001e0228d825673365816b020f1bfa","uri":"spotify:track:7AuMPJMHY3TYeZEZsEy0CF","trackType":"spotify","seek":0,"duration":174,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:43 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 39 Nov 25 07:39:43 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"mailbox (feat. Hava)","artist":"Dardan, Hava","album":"MISTER DARDY","albumart":"https://i.scdn.co/image/ab67616d00001e0228d825673365816b020f1bfa","uri":"spotify:track:7AuMPJMHY3TYeZEZsEy0CF","trackType":"spotify","seek":0,"duration":174,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:43 teenieboombox volumio[1025]: verbose: CURRENT POSITION 39 Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService pause Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:43 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 39 Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:43 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:43 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:43 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=error msg="failed put state after update" error="put state request failed with status 429: Too many requests for user" Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=trace msg="emitting websocket event: playing" Nov 25 07:39:43 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7AuMPJMHY3TYeZEZsEy0CF","play_origin":"go-librespot"}} Nov 25 07:39:43 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:43 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"mailbox (feat. Hava)","artist":"Dardan, Hava","album":"MISTER DARDY","albumart":"https://i.scdn.co/image/ab67616d00001e0228d825673365816b020f1bfa","uri":"spotify:track:7AuMPJMHY3TYeZEZsEy0CF","trackType":"spotify","seek":0,"duration":174,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:43 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 39 Nov 25 07:39:43 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"mailbox (feat. Hava)","artist":"Dardan, Hava","album":"MISTER DARDY","albumart":"https://i.scdn.co/image/ab67616d00001e0228d825673365816b020f1bfa","uri":"spotify:track:7AuMPJMHY3TYeZEZsEy0CF","trackType":"spotify","seek":0,"duration":174,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:43 teenieboombox volumio[1025]: verbose: CURRENT POSITION 39 Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:43 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:43 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:43+01:00" level=debug msg="fetched chunk 3/13, size: 524288" uri="spotify:track:7AuMPJMHY3TYeZEZsEy0CF" Nov 25 07:39:44 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:44 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"mailbox (feat. Hava)","artist":"Dardan, Hava","album":"MISTER DARDY","albumart":"https://i.scdn.co/image/ab67616d00001e0228d825673365816b020f1bfa","uri":"spotify:track:7AuMPJMHY3TYeZEZsEy0CF","trackType":"spotify","seek":0,"duration":174,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:44 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:44 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 39 Nov 25 07:39:44 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"mailbox (feat. Hava)","artist":"Dardan, Hava","album":"MISTER DARDY","albumart":"https://i.scdn.co/image/ab67616d00001e0228d825673365816b020f1bfa","uri":"spotify:track:7AuMPJMHY3TYeZEZsEy0CF","trackType":"spotify","seek":0,"duration":174,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:44 teenieboombox volumio[1025]: verbose: CURRENT POSITION 39 Nov 25 07:39:44 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:44 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus play Nov 25 07:39:44 teenieboombox volumio[1025]: info: Received an update from plugin. extracting info from payload Nov 25 07:39:44 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:44 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 39 Nov 25 07:39:44 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:44 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:44 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:44 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:44 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:44 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 39 Nov 25 07:39:44 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:44 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:44 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:44 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:44 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:44 teenieboombox volumio[1025]: info: camilladsp spawned new process with pid 30002, instance 1, run: true Nov 25 07:39:44 teenieboombox kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioNext Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreStateMachine::next Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreStateMachine::stop Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreStateMachine::stPlaybackTimer Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:45 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:45 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 39 Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:45 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:45 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreStateMachine::serviceStop Nov 25 07:39:45 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 39 Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceStop Nov 25 07:39:45 teenieboombox volumio[1025]: info: Spotify Stop Nov 25 07:39:45 teenieboombox volumio[1025]: SPOTIFY: SPOTIFY STOP Nov 25 07:39:45 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","position":39,"title":"mailbox (feat. Hava)","artist":"Dardan","album":"MISTER DARDY","albumart":"https://i.scdn.co/image/ab67616d0000b27328d825673365816b020f1bfa","uri":"spotify:track:7AuMPJMHY3TYeZEZsEy0CF","trackType":"spotify","codec":"ogg","seek":0,"duration":174,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":false,"repeatSingle":false,"consume":false,"volume":46,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Nov 25 07:39:45 teenieboombox volumio[1025]: info: Sending Spotify command to local API: /player/pause Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreStateMachine::play index undefined Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:45 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 15 Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreStateMachine::startPlaybackTimer Nov 25 07:39:45 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 15 Nov 25 07:39:45 teenieboombox volumio[1025]: info: [1732516785831] ControllerSpotify::clearAddPlayTrack Nov 25 07:39:45 teenieboombox volumio[1025]: info: Sending Spotify command with payload to local API: /player/play Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:45 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:45 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:45 teenieboombox volumio[1025]: info: touch_display: Setting screensaver timeout to 120 seconds. Nov 25 07:39:45 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:45+01:00" level=debug msg="pause track at 2654ms" Nov 25 07:39:45 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:45+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:45 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:45+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:45 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:45+01:00" level=trace msg="emitting websocket event: paused" Nov 25 07:39:45 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:7AuMPJMHY3TYeZEZsEy0CF","play_origin":"go-librespot"}} Nov 25 07:39:45 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:45 teenieboombox volumio[1025]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":1000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:45 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 15 Nov 25 07:39:45 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":1000,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:45 teenieboombox volumio[1025]: verbose: CURRENT POSITION 15 Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService pause Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:45 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 15 Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:45 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:45 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:45 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:46 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=debug msg="resolved context of track" uri="spotify:track:5NtZlpRVomRYn5FYVwAYtO" Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5NtZlpRVomRYn5FYVwAYtO" Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5NtZlpRVomRYn5FYVwAYtO" Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=trace msg="emitting websocket event: will_play" Nov 25 07:39:46 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5NtZlpRVomRYn5FYVwAYtO","play_origin":"go-librespot"}} Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=debug msg="selected format OGG_VORBIS_320 (d5eeed190f77a85f8ea52714b102ad83e9ec696d)" uri="spotify:track:5NtZlpRVomRYn5FYVwAYtO" Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=debug msg="requested aes key for file d5eeed190f77a85f8ea52714b102ad83e9ec696d, gid: 5NtZlpRVomRYn5FYVwAYtO" Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=debug msg="fetched first chunk of 13, total size is 6667080 bytes" uri="spotify:track:5NtZlpRVomRYn5FYVwAYtO" Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:5NtZlpRVomRYn5FYVwAYtO" Nov 25 07:39:46 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 25 07:39:46 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 25 07:39:46 teenieboombox volumio[1025]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=info msg="loaded track \"Superstars\" (paused: false, position: 0ms, duration: 139234ms, prefetched: false)" uri="spotify:track:5NtZlpRVomRYn5FYVwAYtO" Nov 25 07:39:46 teenieboombox volumio[1025]: info: FusionDsp - Effects disabled Nov 25 07:39:46 teenieboombox volumio[1025]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=trace msg="scheduling prefetch in 109s" Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=trace msg="emitting websocket event: metadata" Nov 25 07:39:46 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5NtZlpRVomRYn5FYVwAYtO","name":"Superstars","artist_names":["Jazeek"],"album_name":"NINETYNINE","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02d0d9cb06513819a6a697894e","position":0,"duration":139234,"release_date":"year:2024 month:1 day:12","track_number":11,"disc_number":1}} Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=debug msg="fetched chunk 1/12, size: 524288" uri="spotify:track:5NtZlpRVomRYn5FYVwAYtO" Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=debug msg="fetched chunk 2/12, size: 524288" uri="spotify:track:5NtZlpRVomRYn5FYVwAYtO" Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=trace msg="emitting websocket event: playing" Nov 25 07:39:46 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5NtZlpRVomRYn5FYVwAYtO","play_origin":"go-librespot"}} Nov 25 07:39:46 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:46 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"Superstars","artist":"Jazeek","album":"NINETYNINE","albumart":"https://i.scdn.co/image/ab67616d00001e02d0d9cb06513819a6a697894e","uri":"spotify:track:5NtZlpRVomRYn5FYVwAYtO","trackType":"spotify","seek":0,"duration":139,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:46 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:46 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 15 Nov 25 07:39:46 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Superstars","artist":"Jazeek","album":"NINETYNINE","albumart":"https://i.scdn.co/image/ab67616d00001e02d0d9cb06513819a6a697894e","uri":"spotify:track:5NtZlpRVomRYn5FYVwAYtO","trackType":"spotify","seek":0,"duration":139,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:46 teenieboombox volumio[1025]: verbose: CURRENT POSITION 15 Nov 25 07:39:46 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:46 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:46 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:46+01:00" level=debug msg="fetched chunk 3/12, size: 524288" uri="spotify:track:5NtZlpRVomRYn5FYVwAYtO" Nov 25 07:39:46 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:46 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"Superstars","artist":"Jazeek","album":"NINETYNINE","albumart":"https://i.scdn.co/image/ab67616d00001e02d0d9cb06513819a6a697894e","uri":"spotify:track:5NtZlpRVomRYn5FYVwAYtO","trackType":"spotify","seek":0,"duration":139,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:46 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:46 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 15 Nov 25 07:39:46 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Superstars","artist":"Jazeek","album":"NINETYNINE","albumart":"https://i.scdn.co/image/ab67616d00001e02d0d9cb06513819a6a697894e","uri":"spotify:track:5NtZlpRVomRYn5FYVwAYtO","trackType":"spotify","seek":0,"duration":139,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:46 teenieboombox volumio[1025]: verbose: CURRENT POSITION 15 Nov 25 07:39:46 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:46 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus play Nov 25 07:39:46 teenieboombox volumio[1025]: info: Received an update from plugin. extracting info from payload Nov 25 07:39:46 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:46 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 15 Nov 25 07:39:46 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:46 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:46 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:46 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:46 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:46 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 15 Nov 25 07:39:46 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:46 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:46 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:46 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:46 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:46 teenieboombox volumio[1025]: info: camilladsp spawned new process with pid 30027, instance 1, run: true Nov 25 07:39:46 teenieboombox kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioNext Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreStateMachine::next Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreStateMachine::stop Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreStateMachine::stPlaybackTimer Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:47 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:47 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 15 Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:47 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:47 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreStateMachine::serviceStop Nov 25 07:39:47 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 15 Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceStop Nov 25 07:39:47 teenieboombox volumio[1025]: info: Spotify Stop Nov 25 07:39:47 teenieboombox volumio[1025]: SPOTIFY: SPOTIFY STOP Nov 25 07:39:47 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","position":15,"title":"Superstars","artist":"Jazeek","album":"NINETYNINE","albumart":"https://i.scdn.co/image/ab67616d0000b273d0d9cb06513819a6a697894e","uri":"spotify:track:5NtZlpRVomRYn5FYVwAYtO","trackType":"spotify","codec":"ogg","seek":0,"duration":139,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":false,"repeatSingle":false,"consume":false,"volume":46,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Nov 25 07:39:47 teenieboombox volumio[1025]: info: Sending Spotify command to local API: /player/pause Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreStateMachine::play index undefined Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:47 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 8 Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreStateMachine::startPlaybackTimer Nov 25 07:39:47 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 8 Nov 25 07:39:47 teenieboombox volumio[1025]: info: [1732516787583] ControllerSpotify::clearAddPlayTrack Nov 25 07:39:47 teenieboombox volumio[1025]: info: Sending Spotify command with payload to local API: /player/play Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:47 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:47 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:47 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:47+01:00" level=debug msg="pause track at 1812ms" Nov 25 07:39:47 teenieboombox volumio[1025]: info: touch_display: Setting screensaver timeout to 120 seconds. Nov 25 07:39:47 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:47+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:47 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:47+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:47 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:47+01:00" level=trace msg="emitting websocket event: paused" Nov 25 07:39:47 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5NtZlpRVomRYn5FYVwAYtO","play_origin":"go-librespot"}} Nov 25 07:39:47 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:47 teenieboombox volumio[1025]: SPOTIFY: {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:47 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 8 Nov 25 07:39:47 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"","artist":"","album":"","albumart":"/albumart","uri":"","trackType":"spotify","seek":0,"duration":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:47 teenieboombox volumio[1025]: verbose: CURRENT POSITION 8 Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService pause Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:47 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 8 Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:47 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:47 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:47 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:47 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:47 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:47+01:00" level=debug msg="resolved context of track" uri="spotify:track:6jnR8dYSsKNqj1lVVFT5R0" Nov 25 07:39:47 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:47+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:6jnR8dYSsKNqj1lVVFT5R0" Nov 25 07:39:47 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:47+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:6jnR8dYSsKNqj1lVVFT5R0" Nov 25 07:39:47 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:47+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:47 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:47+01:00" level=trace msg="emitting websocket event: will_play" Nov 25 07:39:47 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6jnR8dYSsKNqj1lVVFT5R0","play_origin":"go-librespot"}} Nov 25 07:39:47 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:47+01:00" level=debug msg="selected format OGG_VORBIS_320 (4ee64d24fcbaa67a30ec8dbe5a38ad2c1d20fe8c)" uri="spotify:track:6jnR8dYSsKNqj1lVVFT5R0" Nov 25 07:39:47 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:47+01:00" level=debug msg="requested aes key for file 4ee64d24fcbaa67a30ec8dbe5a38ad2c1d20fe8c, gid: 6jnR8dYSsKNqj1lVVFT5R0" Nov 25 07:39:48 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:48+01:00" level=debug msg="fetched first chunk of 11, total size is 5599924 bytes" uri="spotify:track:6jnR8dYSsKNqj1lVVFT5R0" Nov 25 07:39:48 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:48+01:00" level=trace msg="seek to 0ms (diff: -26ms, samples: 0, bytes: 939)" uri="spotify:track:6jnR8dYSsKNqj1lVVFT5R0" Nov 25 07:39:48 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 25 07:39:48 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 25 07:39:48 teenieboombox volumio[1025]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 25 07:39:48 teenieboombox volumio[1025]: info: FusionDsp - Effects disabled Nov 25 07:39:48 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:48+01:00" level=info msg="loaded track \"BLEIB' ÜBER NACHT (feat. Luciano)\" (paused: false, position: 0ms, duration: 132000ms, prefetched: false)" uri="spotify:track:6jnR8dYSsKNqj1lVVFT5R0" Nov 25 07:39:48 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 25 07:39:48 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 25 07:39:48 teenieboombox volumio[1025]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 25 07:39:48 teenieboombox volumio[1025]: info: FusionDsp - Effects disabled Nov 25 07:39:48 teenieboombox volumio[1025]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 25 07:39:48 teenieboombox volumio[1025]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 25 07:39:48 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:48+01:00" level=debug msg="fetched chunk 1/10, size: 524288" uri="spotify:track:6jnR8dYSsKNqj1lVVFT5R0" Nov 25 07:39:48 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:48+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:48 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:48+01:00" level=trace msg="scheduling prefetch in 102s" Nov 25 07:39:48 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:48+01:00" level=trace msg="emitting websocket event: metadata" Nov 25 07:39:48 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6jnR8dYSsKNqj1lVVFT5R0","name":"BLEIB' ÜBER NACHT (feat. Luciano)","artist_names":["KALIM","Luciano"],"album_name":"T.O.T.Y.","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02b8edc8e6156e995e379e6f00","position":0,"duration":132000,"release_date":"year:2021 month:10 day:28","track_number":9,"disc_number":1}} Nov 25 07:39:48 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:48+01:00" level=debug msg="fetched chunk 2/10, size: 524288" uri="spotify:track:6jnR8dYSsKNqj1lVVFT5R0" Nov 25 07:39:48 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:48+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:48 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:48+01:00" level=trace msg="emitting websocket event: playing" Nov 25 07:39:48 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6jnR8dYSsKNqj1lVVFT5R0","play_origin":"go-librespot"}} Nov 25 07:39:48 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:48 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"BLEIB' ÜBER NACHT (feat. Luciano)","artist":"KALIM, Luciano","album":"T.O.T.Y.","albumart":"https://i.scdn.co/image/ab67616d00001e02b8edc8e6156e995e379e6f00","uri":"spotify:track:6jnR8dYSsKNqj1lVVFT5R0","trackType":"spotify","seek":0,"duration":132,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:48 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:48 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 8 Nov 25 07:39:48 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"BLEIB' ÜBER NACHT (feat. Luciano)","artist":"KALIM, Luciano","album":"T.O.T.Y.","albumart":"https://i.scdn.co/image/ab67616d00001e02b8edc8e6156e995e379e6f00","uri":"spotify:track:6jnR8dYSsKNqj1lVVFT5R0","trackType":"spotify","seek":0,"duration":132,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:48 teenieboombox volumio[1025]: verbose: CURRENT POSITION 8 Nov 25 07:39:48 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:48 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:48 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:48+01:00" level=debug msg="fetched chunk 3/10, size: 524288" uri="spotify:track:6jnR8dYSsKNqj1lVVFT5R0" Nov 25 07:39:48 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:48 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"BLEIB' ÜBER NACHT (feat. Luciano)","artist":"KALIM, Luciano","album":"T.O.T.Y.","albumart":"https://i.scdn.co/image/ab67616d00001e02b8edc8e6156e995e379e6f00","uri":"spotify:track:6jnR8dYSsKNqj1lVVFT5R0","trackType":"spotify","seek":0,"duration":132,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:48 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:48 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 8 Nov 25 07:39:48 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"BLEIB' ÜBER NACHT (feat. Luciano)","artist":"KALIM, Luciano","album":"T.O.T.Y.","albumart":"https://i.scdn.co/image/ab67616d00001e02b8edc8e6156e995e379e6f00","uri":"spotify:track:6jnR8dYSsKNqj1lVVFT5R0","trackType":"spotify","seek":0,"duration":132,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:48 teenieboombox volumio[1025]: verbose: CURRENT POSITION 8 Nov 25 07:39:48 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:48 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus play Nov 25 07:39:48 teenieboombox volumio[1025]: info: Received an update from plugin. extracting info from payload Nov 25 07:39:48 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:48 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 8 Nov 25 07:39:48 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:48 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:48 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:48 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:48 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:48 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 8 Nov 25 07:39:48 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:48 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:48 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:48 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:48 teenieboombox volumio[1025]: info: camilladsp spawned new process with pid 30039, instance 1, run: true Nov 25 07:39:48 teenieboombox kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 25 07:39:49 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioNext Nov 25 07:39:49 teenieboombox volumio[1025]: info: CoreStateMachine::next Nov 25 07:39:49 teenieboombox volumio[1025]: info: CoreStateMachine::stop Nov 25 07:39:49 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:49 teenieboombox volumio[1025]: info: CoreStateMachine::stPlaybackTimer Nov 25 07:39:49 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:49 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:49 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:49 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 8 Nov 25 07:39:49 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:49 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:49 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:49 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:49 teenieboombox volumio[1025]: info: CoreStateMachine::serviceStop Nov 25 07:39:49 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 8 Nov 25 07:39:49 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceStop Nov 25 07:39:49 teenieboombox volumio[1025]: info: Spotify Stop Nov 25 07:39:49 teenieboombox volumio[1025]: SPOTIFY: SPOTIFY STOP Nov 25 07:39:49 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","position":8,"title":"BLEIB' ÜBER NACHT (feat. Luciano)","artist":"KALIM","album":"T.O.T.Y.","albumart":"https://i.scdn.co/image/ab67616d0000b273b8edc8e6156e995e379e6f00","uri":"spotify:track:6jnR8dYSsKNqj1lVVFT5R0","trackType":"spotify","codec":"ogg","seek":0,"duration":132,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":false,"repeatSingle":false,"consume":false,"volume":46,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Nov 25 07:39:49 teenieboombox volumio[1025]: info: Sending Spotify command to local API: /player/pause Nov 25 07:39:49 teenieboombox volumio[1025]: info: CoreStateMachine::play index undefined Nov 25 07:39:49 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:49 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:49 teenieboombox volumio[1025]: info: CoreStateMachine::startPlaybackTimer Nov 25 07:39:49 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:49 teenieboombox volumio[1025]: info: [1732516789771] ControllerSpotify::clearAddPlayTrack Nov 25 07:39:49 teenieboombox volumio[1025]: info: Sending Spotify command with payload to local API: /player/play Nov 25 07:39:49 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:49 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:49 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:49 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:49+01:00" level=debug msg="pause track at 2275ms" Nov 25 07:39:49 teenieboombox volumio[1025]: info: touch_display: Setting screensaver timeout to 120 seconds. Nov 25 07:39:49 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:49+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:49 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:49+01:00" level=debug msg="resolved context of track" uri="spotify:track:2q7jpVfCtcuRwcur9nQeuC" Nov 25 07:39:49 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:49+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:2q7jpVfCtcuRwcur9nQeuC" Nov 25 07:39:49 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:49+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2q7jpVfCtcuRwcur9nQeuC" Nov 25 07:39:49 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:49+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:49 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:49+01:00" level=trace msg="emitting websocket event: will_play" Nov 25 07:39:49 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","play_origin":"go-librespot"}} Nov 25 07:39:50 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:50+01:00" level=debug msg="selected format OGG_VORBIS_320 (5fdba45713a14ea41ec9c7ba9b1f595e03b5e01d)" uri="spotify:track:2q7jpVfCtcuRwcur9nQeuC" Nov 25 07:39:50 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:50+01:00" level=debug msg="requested aes key for file 5fdba45713a14ea41ec9c7ba9b1f595e03b5e01d, gid: 2q7jpVfCtcuRwcur9nQeuC" Nov 25 07:39:50 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:50+01:00" level=debug msg="fetched first chunk of 17, total size is 8838536 bytes" uri="spotify:track:2q7jpVfCtcuRwcur9nQeuC" Nov 25 07:39:50 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:50+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:2q7jpVfCtcuRwcur9nQeuC" Nov 25 07:39:50 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 25 07:39:50 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 25 07:39:50 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:50+01:00" level=info msg="loaded track \"PARADISE (MIT DIR)\" (paused: false, position: 0ms, duration: 192975ms, prefetched: false)" uri="spotify:track:2q7jpVfCtcuRwcur9nQeuC" Nov 25 07:39:50 teenieboombox volumio[1025]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 25 07:39:50 teenieboombox volumio[1025]: info: FusionDsp - Effects disabled Nov 25 07:39:50 teenieboombox volumio[1025]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 25 07:39:50 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:50+01:00" level=debug msg="fetched chunk 1/16, size: 524288" uri="spotify:track:2q7jpVfCtcuRwcur9nQeuC" Nov 25 07:39:50 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:50+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:50 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:50+01:00" level=trace msg="scheduling prefetch in 163s" Nov 25 07:39:50 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:50+01:00" level=trace msg="emitting websocket event: metadata" Nov 25 07:39:50 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","name":"PARADISE (MIT DIR)","artist_names":["Liaze","equal"],"album_name":"MIXED FEELINGS","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02bbc1189420a553b9b0990870","position":0,"duration":192975,"release_date":"year:2022 month:5 day:20","track_number":1,"disc_number":1}} Nov 25 07:39:50 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:50+01:00" level=debug msg="fetched chunk 3/16, size: 524288" uri="spotify:track:2q7jpVfCtcuRwcur9nQeuC" Nov 25 07:39:50 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:50+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:50 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:50+01:00" level=trace msg="emitting websocket event: paused" Nov 25 07:39:50 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","play_origin":"go-librespot"}} Nov 25 07:39:50 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:50 teenieboombox volumio[1025]: SPOTIFY: {"status":"pause","service":"spop","title":"PARADISE (MIT DIR)","artist":"Liaze, equal","album":"MIXED FEELINGS","albumart":"https://i.scdn.co/image/ab67616d00001e02bbc1189420a553b9b0990870","uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","trackType":"spotify","seek":0,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:50 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:50 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"PARADISE (MIT DIR)","artist":"Liaze, equal","album":"MIXED FEELINGS","albumart":"https://i.scdn.co/image/ab67616d00001e02bbc1189420a553b9b0990870","uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","trackType":"spotify","seek":0,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:50 teenieboombox volumio[1025]: verbose: CURRENT POSITION 23 Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService pause Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:50 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:50 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:50 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:50 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:50 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:50+01:00" level=debug msg="fetched chunk 2/16, size: 524288" uri="spotify:track:2q7jpVfCtcuRwcur9nQeuC" Nov 25 07:39:50 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:50+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:50 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:50+01:00" level=trace msg="emitting websocket event: playing" Nov 25 07:39:50 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","play_origin":"go-librespot"}} Nov 25 07:39:50 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:50 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"PARADISE (MIT DIR)","artist":"Liaze, equal","album":"MIXED FEELINGS","albumart":"https://i.scdn.co/image/ab67616d00001e02bbc1189420a553b9b0990870","uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","trackType":"spotify","seek":0,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:50 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:50 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"PARADISE (MIT DIR)","artist":"Liaze, equal","album":"MIXED FEELINGS","albumart":"https://i.scdn.co/image/ab67616d00001e02bbc1189420a553b9b0990870","uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","trackType":"spotify","seek":0,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:50 teenieboombox volumio[1025]: verbose: CURRENT POSITION 23 Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:50 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:50 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"PARADISE (MIT DIR)","artist":"Liaze, equal","album":"MIXED FEELINGS","albumart":"https://i.scdn.co/image/ab67616d00001e02bbc1189420a553b9b0990870","uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","trackType":"spotify","seek":0,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:50 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:50 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"PARADISE (MIT DIR)","artist":"Liaze, equal","album":"MIXED FEELINGS","albumart":"https://i.scdn.co/image/ab67616d00001e02bbc1189420a553b9b0990870","uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","trackType":"spotify","seek":0,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:50 teenieboombox volumio[1025]: verbose: CURRENT POSITION 23 Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus play Nov 25 07:39:50 teenieboombox volumio[1025]: info: Received an update from plugin. extracting info from payload Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:50 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:50 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:50 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:50 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:50 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:50 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:50 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:50 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:50 teenieboombox volumio[1025]: info: camilladsp spawned new process with pid 30053, instance 1, run: true Nov 25 07:39:50 teenieboombox kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPrevious Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::previous Nov 25 07:39:54 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:54 teenieboombox volumio[1025]: info: Spotify seek to: 0 Nov 25 07:39:54 teenieboombox volumio[1025]: info: Sending Spotify command with payload to local API: /player/seek Nov 25 07:39:54 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:54+01:00" level=debug msg="seek track to 0ms" Nov 25 07:39:54 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:54+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:2q7jpVfCtcuRwcur9nQeuC" Nov 25 07:39:54 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:54+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:54 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:54+01:00" level=trace msg="scheduling prefetch in 163s" Nov 25 07:39:54 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:54+01:00" level=trace msg="emitting websocket event: seek" Nov 25 07:39:54 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","position":0,"duration":192975,"play_origin":"go-librespot"}} Nov 25 07:39:54 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:54 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"PARADISE (MIT DIR)","artist":"Liaze, equal","album":"MIXED FEELINGS","albumart":"https://i.scdn.co/image/ab67616d00001e02bbc1189420a553b9b0990870","uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","trackType":"spotify","seek":0,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:54 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:54 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"PARADISE (MIT DIR)","artist":"Liaze, equal","album":"MIXED FEELINGS","albumart":"https://i.scdn.co/image/ab67616d00001e02bbc1189420a553b9b0990870","uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","trackType":"spotify","seek":0,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:54 teenieboombox volumio[1025]: verbose: CURRENT POSITION 23 Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus play Nov 25 07:39:54 teenieboombox volumio[1025]: info: Received an update from plugin. extracting info from payload Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:54 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:54 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:54 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:54 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:54 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:54 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:54 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:54 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPrevious Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::previous Nov 25 07:39:54 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::stop Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::stPlaybackTimer Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:54 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:54 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:54 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:54 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::serviceStop Nov 25 07:39:54 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceStop Nov 25 07:39:54 teenieboombox volumio[1025]: info: Spotify Stop Nov 25 07:39:54 teenieboombox volumio[1025]: SPOTIFY: SPOTIFY STOP Nov 25 07:39:54 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","position":23,"title":"PARADISE (MIT DIR)","artist":"Liaze","album":"MIXED FEELINGS","albumart":"https://i.scdn.co/image/ab67616d0000b273bbc1189420a553b9b0990870","uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","trackType":"spotify","codec":"ogg","seek":0,"duration":192,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":false,"repeatSingle":false,"consume":false,"volume":46,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Nov 25 07:39:54 teenieboombox volumio[1025]: info: Sending Spotify command to local API: /player/pause Nov 25 07:39:54 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:54 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:54+01:00" level=debug msg="pause track at 207ms" Nov 25 07:39:54 teenieboombox volumio[1025]: info: touch_display: Setting screensaver timeout to 120 seconds. Nov 25 07:39:54 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:54+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:54 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:54+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:54 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:54+01:00" level=trace msg="emitting websocket event: paused" Nov 25 07:39:54 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","play_origin":"go-librespot"}} Nov 25 07:39:54 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:54 teenieboombox volumio[1025]: SPOTIFY: {"status":"pause","service":"spop","title":"PARADISE (MIT DIR)","artist":"Liaze, equal","album":"MIXED FEELINGS","albumart":"https://i.scdn.co/image/ab67616d00001e02bbc1189420a553b9b0990870","uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","trackType":"spotify","seek":1000,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:54 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:54 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"PARADISE (MIT DIR)","artist":"Liaze, equal","album":"MIXED FEELINGS","albumart":"https://i.scdn.co/image/ab67616d00001e02bbc1189420a553b9b0990870","uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","trackType":"spotify","seek":1000,"duration":192,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:54 teenieboombox volumio[1025]: verbose: CURRENT POSITION 23 Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService pause Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:54 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 23 Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:54 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:54 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:54 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPrevious Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::previous Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:54 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::serviceClearAddPlay Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceClearAddPlayTracks Nov 25 07:39:54 teenieboombox volumio[1025]: error: WARNING: No clearAddPlayTracks method for service spop Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPrevious Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::previous Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:54 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::serviceClearAddPlay Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceClearAddPlayTracks Nov 25 07:39:54 teenieboombox volumio[1025]: error: WARNING: No clearAddPlayTracks method for service spop Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::play index undefined Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:54 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 5 Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::startPlaybackTimer Nov 25 07:39:54 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 5 Nov 25 07:39:54 teenieboombox volumio[1025]: info: [1732516794922] ControllerSpotify::clearAddPlayTrack Nov 25 07:39:54 teenieboombox volumio[1025]: info: Sending Spotify command with payload to local API: /player/play Nov 25 07:39:54 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:54+01:00" level=debug msg="resolved context of track" uri="spotify:track:0Ues1lQeACKsKVwmLrrKwN" Nov 25 07:39:54 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:54+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:0Ues1lQeACKsKVwmLrrKwN" Nov 25 07:39:54 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:54+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:0Ues1lQeACKsKVwmLrrKwN" Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPrevious Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::previous Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:54 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreStateMachine::serviceClearAddPlay Nov 25 07:39:54 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceClearAddPlayTracks Nov 25 07:39:54 teenieboombox volumio[1025]: error: WARNING: No clearAddPlayTracks method for service spop Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=trace msg="emitting websocket event: will_play" Nov 25 07:39:55 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0Ues1lQeACKsKVwmLrrKwN","play_origin":"go-librespot"}} Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=debug msg="selected format OGG_VORBIS_320 (fdfe6967254067c8030586d459d48fcd25df8f5a)" uri="spotify:track:0Ues1lQeACKsKVwmLrrKwN" Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=debug msg="requested aes key for file fdfe6967254067c8030586d459d48fcd25df8f5a, gid: 0Ues1lQeACKsKVwmLrrKwN" Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPrevious Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::previous Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:55 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::serviceClearAddPlay Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceClearAddPlayTracks Nov 25 07:39:55 teenieboombox volumio[1025]: error: WARNING: No clearAddPlayTracks method for service spop Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=debug msg="fetched first chunk of 8, total size is 4126284 bytes" uri="spotify:track:0Ues1lQeACKsKVwmLrrKwN" Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:0Ues1lQeACKsKVwmLrrKwN" Nov 25 07:39:55 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 25 07:39:55 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 25 07:39:55 teenieboombox volumio[1025]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 25 07:39:55 teenieboombox volumio[1025]: info: FusionDsp - Effects disabled Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=info msg="loaded track \"Mond\" (paused: false, position: 0ms, duration: 102733ms, prefetched: false)" uri="spotify:track:0Ues1lQeACKsKVwmLrrKwN" Nov 25 07:39:55 teenieboombox volumio[1025]: error: FusionDsp - WebSocket error: [object Object] Nov 25 07:39:55 teenieboombox volumio[1025]: info: camilladsp spawned new process with pid 30066, instance 1, run: true Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=debug msg="fetched chunk 1/7, size: 524288" uri="spotify:track:0Ues1lQeACKsKVwmLrrKwN" Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=trace msg="scheduling prefetch in 72s" Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=trace msg="emitting websocket event: metadata" Nov 25 07:39:55 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0Ues1lQeACKsKVwmLrrKwN","name":"Mond","artist_names":["Lucio101"],"album_name":"MITTENDRIN","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02dbc191aa2d23a4d14e590ebb","position":0,"duration":102733,"release_date":"year:2020 month:9 day:18","track_number":9,"disc_number":1}} Nov 25 07:39:55 teenieboombox kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=debug msg="fetched chunk 3/7, size: 524288" uri="spotify:track:0Ues1lQeACKsKVwmLrrKwN" Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=trace msg="emitting websocket event: playing" Nov 25 07:39:55 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0Ues1lQeACKsKVwmLrrKwN","play_origin":"go-librespot"}} Nov 25 07:39:55 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:55 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"Mond","artist":"Lucio101","album":"MITTENDRIN","albumart":"https://i.scdn.co/image/ab67616d00001e02dbc191aa2d23a4d14e590ebb","uri":"spotify:track:0Ues1lQeACKsKVwmLrrKwN","trackType":"spotify","seek":0,"duration":102,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:55 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 14 Nov 25 07:39:55 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Mond","artist":"Lucio101","album":"MITTENDRIN","albumart":"https://i.scdn.co/image/ab67616d00001e02dbc191aa2d23a4d14e590ebb","uri":"spotify:track:0Ues1lQeACKsKVwmLrrKwN","trackType":"spotify","seek":0,"duration":102,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:55 teenieboombox volumio[1025]: verbose: CURRENT POSITION 14 Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPrevious Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::previous Nov 25 07:39:55 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 14 Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::stop Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::stPlaybackTimer Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:55 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:55 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 14 Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:55 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:55 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::serviceStop Nov 25 07:39:55 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 14 Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceStop Nov 25 07:39:55 teenieboombox volumio[1025]: info: Spotify Stop Nov 25 07:39:55 teenieboombox volumio[1025]: SPOTIFY: SPOTIFY STOP Nov 25 07:39:55 teenieboombox volumio[1025]: SPOTIFY: {"status":"stop","position":23,"title":"PARADISE (MIT DIR)","artist":"Liaze","album":"MIXED FEELINGS","albumart":"https://i.scdn.co/image/ab67616d0000b273bbc1189420a553b9b0990870","uri":"spotify:track:2q7jpVfCtcuRwcur9nQeuC","trackType":"spotify","codec":"ogg","seek":308,"duration":192,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":false,"repeatSingle":false,"consume":false,"volume":46,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Nov 25 07:39:55 teenieboombox volumio[1025]: info: Sending Spotify command to local API: /player/pause Nov 25 07:39:55 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=debug msg="fetched chunk 2/7, size: 524288" uri="spotify:track:0Ues1lQeACKsKVwmLrrKwN" Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=debug msg="pause track at 528ms" Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=trace msg="emitting websocket event: paused" Nov 25 07:39:55 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:0Ues1lQeACKsKVwmLrrKwN","play_origin":"go-librespot"}} Nov 25 07:39:55 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:55 teenieboombox volumio[1025]: SPOTIFY: {"status":"pause","service":"spop","title":"Mond","artist":"Lucio101","album":"MITTENDRIN","albumart":"https://i.scdn.co/image/ab67616d00001e02dbc191aa2d23a4d14e590ebb","uri":"spotify:track:0Ues1lQeACKsKVwmLrrKwN","trackType":"spotify","seek":0,"duration":102,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:55 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 14 Nov 25 07:39:55 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Mond","artist":"Lucio101","album":"MITTENDRIN","albumart":"https://i.scdn.co/image/ab67616d00001e02dbc191aa2d23a4d14e590ebb","uri":"spotify:track:0Ues1lQeACKsKVwmLrrKwN","trackType":"spotify","seek":0,"duration":102,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:55 teenieboombox volumio[1025]: verbose: CURRENT POSITION 14 Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService pause Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:55 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 14 Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:55 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:55 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:55 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:55 teenieboombox volumio[1025]: info: camilladsp spawned new process with pid 30073, instance 1, run: true Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPrevious Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::previous Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:55 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::serviceClearAddPlay Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceClearAddPlayTracks Nov 25 07:39:55 teenieboombox volumio[1025]: error: WARNING: No clearAddPlayTracks method for service spop Nov 25 07:39:55 teenieboombox kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Nov 25 07:39:55 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:55 teenieboombox volumio[1025]: SPOTIFY: {"status":"pause","service":"spop","title":"Mond","artist":"Lucio101","album":"MITTENDRIN","albumart":"https://i.scdn.co/image/ab67616d00001e02dbc191aa2d23a4d14e590ebb","uri":"spotify:track:0Ues1lQeACKsKVwmLrrKwN","trackType":"spotify","seek":0,"duration":102,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:55 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 16 Nov 25 07:39:55 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Mond","artist":"Lucio101","album":"MITTENDRIN","albumart":"https://i.scdn.co/image/ab67616d00001e02dbc191aa2d23a4d14e590ebb","uri":"spotify:track:0Ues1lQeACKsKVwmLrrKwN","trackType":"spotify","seek":0,"duration":102,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:55 teenieboombox volumio[1025]: verbose: CURRENT POSITION 16 Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService pause Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:55 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 16 Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:55 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:55 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:55 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPrevious Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::previous Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:55 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::serviceClearAddPlay Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceClearAddPlayTracks Nov 25 07:39:55 teenieboombox volumio[1025]: error: WARNING: No clearAddPlayTracks method for service spop Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::play index undefined Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 25 07:39:55 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 41 Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::startPlaybackTimer Nov 25 07:39:55 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 41 Nov 25 07:39:55 teenieboombox volumio[1025]: info: [1732516795886] ControllerSpotify::clearAddPlayTrack Nov 25 07:39:55 teenieboombox volumio[1025]: info: Sending Spotify command with payload to local API: /player/play Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPrevious Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::previous Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:55 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreStateMachine::serviceClearAddPlay Nov 25 07:39:55 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceClearAddPlayTracks Nov 25 07:39:55 teenieboombox volumio[1025]: error: WARNING: No clearAddPlayTracks method for service spop Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=debug msg="resolved context of track" uri="spotify:track:5bmJdLadN61i7pGgxHbF5S" Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:5bmJdLadN61i7pGgxHbF5S" Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:5bmJdLadN61i7pGgxHbF5S" Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:55 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:55+01:00" level=trace msg="emitting websocket event: will_play" Nov 25 07:39:55 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5bmJdLadN61i7pGgxHbF5S","play_origin":"go-librespot"}} Nov 25 07:39:56 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:56+01:00" level=debug msg="selected format OGG_VORBIS_320 (e82b9e84ea440789cdc76dd25f666260b35477e6)" uri="spotify:track:5bmJdLadN61i7pGgxHbF5S" Nov 25 07:39:56 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:56+01:00" level=debug msg="requested aes key for file e82b9e84ea440789cdc76dd25f666260b35477e6, gid: 5bmJdLadN61i7pGgxHbF5S" Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPrevious Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::previous Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:56 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::serviceClearAddPlay Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceClearAddPlayTracks Nov 25 07:39:56 teenieboombox volumio[1025]: error: WARNING: No clearAddPlayTracks method for service spop Nov 25 07:39:56 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:56+01:00" level=debug msg="fetched first chunk of 8, total size is 3768584 bytes" uri="spotify:track:5bmJdLadN61i7pGgxHbF5S" Nov 25 07:39:56 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:56+01:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:5bmJdLadN61i7pGgxHbF5S" Nov 25 07:39:56 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 25 07:39:56 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 25 07:39:56 teenieboombox volumio[1025]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 25 07:39:56 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:56+01:00" level=info msg="loaded track \"Grape Soda\" (paused: false, position: 0ms, duration: 77647ms, prefetched: false)" uri="spotify:track:5bmJdLadN61i7pGgxHbF5S" Nov 25 07:39:56 teenieboombox volumio[1025]: info: FusionDsp - Effects disabled Nov 25 07:39:56 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 25 07:39:56 teenieboombox volumio[1025]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 25 07:39:56 teenieboombox volumio[1025]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 25 07:39:56 teenieboombox volumio[1025]: info: FusionDsp - Effects disabled Nov 25 07:39:56 teenieboombox volumio[1025]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 25 07:39:56 teenieboombox volumio[1025]: info: FusionDsp - {"Reload":{"result":"Ok"}} Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPrevious Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::previous Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:56 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::serviceClearAddPlay Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceClearAddPlayTracks Nov 25 07:39:56 teenieboombox volumio[1025]: error: WARNING: No clearAddPlayTracks method for service spop Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPrevious Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::previous Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:56 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::serviceClearAddPlay Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceClearAddPlayTracks Nov 25 07:39:56 teenieboombox volumio[1025]: error: WARNING: No clearAddPlayTracks method for service spop Nov 25 07:39:56 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:56+01:00" level=debug msg="fetched chunk 2/7, size: 524288" uri="spotify:track:5bmJdLadN61i7pGgxHbF5S" Nov 25 07:39:56 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:56+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:56 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:56+01:00" level=trace msg="scheduling prefetch in 47s" Nov 25 07:39:56 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:56+01:00" level=trace msg="emitting websocket event: metadata" Nov 25 07:39:56 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5bmJdLadN61i7pGgxHbF5S","name":"Grape Soda","artist_names":["Lyno Nine8"],"album_name":"Grape Soda","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02f08323525a9b84358cb3492c","position":0,"duration":77647,"release_date":"year:2022 month:3 day:12","track_number":1,"disc_number":1}} Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPrevious Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::previous Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:56 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::serviceClearAddPlay Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceClearAddPlayTracks Nov 25 07:39:56 teenieboombox volumio[1025]: error: WARNING: No clearAddPlayTracks method for service spop Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPrevious Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::previous Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::updateTrackBlock Nov 25 07:39:56 teenieboombox volumio[1025]: info: CorePlayQueue::getTrackBlock Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::serviceClearAddPlay Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreCommandRouter::serviceClearAddPlayTracks Nov 25 07:39:56 teenieboombox volumio[1025]: error: WARNING: No clearAddPlayTracks method for service spop Nov 25 07:39:56 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:56+01:00" level=debug msg="fetched chunk 1/7, size: 524288" uri="spotify:track:5bmJdLadN61i7pGgxHbF5S" Nov 25 07:39:56 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:56+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 25 07:39:56 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:56+01:00" level=trace msg="emitting websocket event: playing" Nov 25 07:39:56 teenieboombox volumio[1025]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5bmJdLadN61i7pGgxHbF5S","play_origin":"go-librespot"}} Nov 25 07:39:56 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:56 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"Grape Soda","artist":"Lyno Nine8","album":"Grape Soda","albumart":"https://i.scdn.co/image/ab67616d00001e02f08323525a9b84358cb3492c","uri":"spotify:track:5bmJdLadN61i7pGgxHbF5S","trackType":"spotify","seek":0,"duration":77,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:56 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 50 Nov 25 07:39:56 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Grape Soda","artist":"Lyno Nine8","album":"Grape Soda","albumart":"https://i.scdn.co/image/ab67616d00001e02f08323525a9b84358cb3492c","uri":"spotify:track:5bmJdLadN61i7pGgxHbF5S","trackType":"spotify","seek":0,"duration":77,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:56 teenieboombox volumio[1025]: verbose: CURRENT POSITION 50 Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:56 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus stop Nov 25 07:39:56 teenieboombox go-librespot[1495]: time="2024-11-25T07:39:56+01:00" level=debug msg="fetched chunk 3/7, size: 524288" uri="spotify:track:5bmJdLadN61i7pGgxHbF5S" Nov 25 07:39:57 teenieboombox volumio[1025]: SPOTIFY: PUSH STATE SPOTIFY Nov 25 07:39:57 teenieboombox volumio[1025]: SPOTIFY: {"status":"play","service":"spop","title":"Grape Soda","artist":"Lyno Nine8","album":"Grape Soda","albumart":"https://i.scdn.co/image/ab67616d00001e02f08323525a9b84358cb3492c","uri":"spotify:track:5bmJdLadN61i7pGgxHbF5S","trackType":"spotify","seek":0,"duration":77,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:57 teenieboombox volumio[1025]: info: CoreCommandRouter::servicePushState Nov 25 07:39:57 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 50 Nov 25 07:39:57 teenieboombox volumio[1025]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Grape Soda","artist":"Lyno Nine8","album":"Grape Soda","albumart":"https://i.scdn.co/image/ab67616d00001e02f08323525a9b84358cb3492c","uri":"spotify:track:5bmJdLadN61i7pGgxHbF5S","trackType":"spotify","seek":0,"duration":77,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 25 07:39:57 teenieboombox volumio[1025]: verbose: CURRENT POSITION 50 Nov 25 07:39:57 teenieboombox volumio[1025]: info: CoreStateMachine::syncState stateService play Nov 25 07:39:57 teenieboombox volumio[1025]: info: CoreStateMachine::syncState currentStatus play Nov 25 07:39:57 teenieboombox volumio[1025]: info: Received an update from plugin. extracting info from payload Nov 25 07:39:57 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:57 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 50 Nov 25 07:39:57 teenieboombox volumio[1025]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 25 07:39:57 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:57 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:57 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:57 teenieboombox volumio[1025]: info: CoreStateMachine::pushState Nov 25 07:39:57 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 50 Nov 25 07:39:57 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPushState Nov 25 07:39:57 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output update for this device Nov 25 07:39:57 teenieboombox volumio[1025]: info: MRS: Pushing multiroomSync output Nov 25 07:39:57 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:57 teenieboombox volumio[1025]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 Nov 25 07:39:58 teenieboombox volumio[1025]: info: CoreCommandRouter::volumioPrevious Nov 25 07:39:58 teenieboombox volumio[1025]: info: CoreStateMachine::previous Nov 25 07:39:58 teenieboombox volumio[1025]: info: CorePlayQueue::getTrack 50 Nov 25 07:39:58 teenieboombox volumio[1025]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 25 07:39:58 teenieboombox volumio[1025]: TypeError: Cannot read property 'service' of undefined Nov 25 07:39:58 teenieboombox volumio[1025]: at CoreStateMachine.previous (/volumio/app/statemachine.js:1325:97) Nov 25 07:39:58 teenieboombox volumio[1025]: at CoreCommandRouter.volumioPrevious (/volumio/app/index.js:97:28) Nov 25 07:39:58 teenieboombox volumio[1025]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:270:33) Nov 25 07:39:58 teenieboombox volumio[1025]: at Socket.emit (events.js:315:20) Nov 25 07:39:58 teenieboombox volumio[1025]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Nov 25 07:39:58 teenieboombox volumio[1025]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Nov 25 07:39:58 teenieboombox volumio[1025]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 25 07:39:59 teenieboombox sudo[30110]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-25 07:38 Nov 25 07:39:59 teenieboombox sudo[30110]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"