-- Logs begin at Sun 2024-08-25 22:58:42 +07, end at Thu 2024-08-29 15:47:51 +07. -- Aug 29 15:46:00 volumio go-librespot[1101]: time="2024-08-29T15:46:00+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:46:00 volumio go-librespot[1101]: time="2024-08-29T15:46:00+07:00" level=trace msg="emitting websocket event: will_play" Aug 29 15:46:00 volumio volumio[809]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5jj7yXcilVsZPpyYtmD28X","play_origin":"go-librespot"}} Aug 29 15:46:00 volumio go-librespot[1101]: time="2024-08-29T15:46:00+07:00" level=debug msg="selected format OGG_VORBIS_320 (12bee5eb673b879329bdb55f725455742872e0df)" uri="spotify:track:5jj7yXcilVsZPpyYtmD28X" Aug 29 15:46:00 volumio go-librespot[1101]: time="2024-08-29T15:46:00+07:00" level=debug msg="requested aes key for file 12bee5eb673b879329bdb55f725455742872e0df, gid: 5jj7yXcilVsZPpyYtmD28X" Aug 29 15:46:00 volumio go-librespot[1101]: time="2024-08-29T15:46:00+07:00" level=debug msg="fetched first chunk of 19, total size is 9820469 bytes" uri="spotify:track:5jj7yXcilVsZPpyYtmD28X" Aug 29 15:46:00 volumio go-librespot[1101]: time="2024-08-29T15:46:00+07:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:5jj7yXcilVsZPpyYtmD28X" Aug 29 15:46:00 volumio go-librespot[1101]: time="2024-08-29T15:46:00+07:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Aug 29 15:46:00 volumio go-librespot[1101]: time="2024-08-29T15:46:00+07:00" level=info msg="loaded track \"จำนน\" (paused: false, position: 0ms, duration: 249230ms, prefetched: false)" uri="spotify:track:5jj7yXcilVsZPpyYtmD28X" Aug 29 15:46:00 volumio go-librespot[1101]: time="2024-08-29T15:46:00+07:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:5jj7yXcilVsZPpyYtmD28X" Aug 29 15:46:00 volumio go-librespot[1101]: time="2024-08-29T15:46:00+07:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:5jj7yXcilVsZPpyYtmD28X" Aug 29 15:46:00 volumio go-librespot[1101]: time="2024-08-29T15:46:00+07:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:5jj7yXcilVsZPpyYtmD28X" Aug 29 15:46:00 volumio go-librespot[1101]: time="2024-08-29T15:46:00+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:46:00 volumio go-librespot[1101]: time="2024-08-29T15:46:00+07:00" level=trace msg="scheduling prefetch in 219s" Aug 29 15:46:00 volumio go-librespot[1101]: time="2024-08-29T15:46:00+07:00" level=trace msg="emitting websocket event: metadata" Aug 29 15:46:00 volumio volumio[809]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5jj7yXcilVsZPpyYtmD28X","name":"จำนน","artist_names":["NONT TANONT"],"album_name":"จำนน","album_cover_url":"https://i.scdn.co/image/ab67616d00001e026449901b3c0a16e51a24ebcc","position":0,"duration":249230,"release_date":"year:2024 month:3 day:14","track_number":1,"disc_number":1}} Aug 29 15:46:00 volumio go-librespot[1101]: time="2024-08-29T15:46:00+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:46:00 volumio go-librespot[1101]: time="2024-08-29T15:46:00+07:00" level=trace msg="emitting websocket event: playing" Aug 29 15:46:00 volumio volumio[809]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5jj7yXcilVsZPpyYtmD28X","play_origin":"go-librespot"}} Aug 29 15:46:00 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Aug 29 15:46:00 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"จำนน","artist":"NONT TANONT","album":"จำนน","albumart":"https://i.scdn.co/image/ab67616d00001e026449901b3c0a16e51a24ebcc","uri":"spotify:track:5jj7yXcilVsZPpyYtmD28X","trackType":"spotify","seek":0,"duration":249,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:46:00 volumio volumio[809]: info: CoreCommandRouter::servicePushState Aug 29 15:46:00 volumio volumio[809]: info: CorePlayQueue::getTrack 7 Aug 29 15:46:00 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"จำนน","artist":"NONT TANONT","album":"จำนน","albumart":"https://i.scdn.co/image/ab67616d00001e026449901b3c0a16e51a24ebcc","uri":"spotify:track:5jj7yXcilVsZPpyYtmD28X","trackType":"spotify","seek":0,"duration":249,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:46:00 volumio volumio[809]: verbose: CURRENT POSITION 7 Aug 29 15:46:00 volumio volumio[809]: info: CoreStateMachine::syncState stateService play Aug 29 15:46:00 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus stop Aug 29 15:46:00 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Aug 29 15:46:00 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"จำนน","artist":"NONT TANONT","album":"จำนน","albumart":"https://i.scdn.co/image/ab67616d00001e026449901b3c0a16e51a24ebcc","uri":"spotify:track:5jj7yXcilVsZPpyYtmD28X","trackType":"spotify","seek":0,"duration":249,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:46:00 volumio volumio[809]: info: CoreCommandRouter::servicePushState Aug 29 15:46:00 volumio volumio[809]: info: CorePlayQueue::getTrack 7 Aug 29 15:46:00 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"จำนน","artist":"NONT TANONT","album":"จำนน","albumart":"https://i.scdn.co/image/ab67616d00001e026449901b3c0a16e51a24ebcc","uri":"spotify:track:5jj7yXcilVsZPpyYtmD28X","trackType":"spotify","seek":0,"duration":249,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:46:00 volumio volumio[809]: verbose: CURRENT POSITION 7 Aug 29 15:46:00 volumio volumio[809]: info: CoreStateMachine::syncState stateService play Aug 29 15:46:00 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus play Aug 29 15:46:00 volumio volumio[809]: info: Received an update from plugin. extracting info from payload Aug 29 15:46:00 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:46:00 volumio volumio[809]: info: CorePlayQueue::getTrack 7 Aug 29 15:46:00 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 15:46:00 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:46:00 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:46:00 volumio volumio[809]: info: CorePlayQueue::getTrack 7 Aug 29 15:46:00 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:46:01 volumio volumio[809]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Total Clients: 9 Aug 29 15:46:01 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Aug 29 15:46:01 volumio volumio[809]: info: CorePlayQueue::getTrack 7 Aug 29 15:46:03 volumio volumio[809]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Total Clients: 10 Aug 29 15:46:03 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Aug 29 15:46:03 volumio volumio[809]: info: CorePlayQueue::getTrack 7 Aug 29 15:46:13 volumio go-librespot[1101]: time="2024-08-29T15:46:13+07:00" level=debug msg="fetched chunk 4/18, size: 524288" uri="spotify:track:5jj7yXcilVsZPpyYtmD28X" Aug 29 15:46:20 volumio volumio[809]: info: peppy_screensaver: Start PeppyMeter Aug 29 15:46:23 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Aug 29 15:46:23 volumio volumio[809]: info: CorePlayQueue::getTrack 7 Aug 29 15:46:23 volumio volumio[809]: info: CoreCommandRouter::volumioPause Aug 29 15:46:23 volumio volumio[809]: info: CoreStateMachine::pause Aug 29 15:46:23 volumio volumio[809]: info: CoreStateMachine::stPlaybackTimer Aug 29 15:46:23 volumio volumio[809]: info: CoreStateMachine::servicePause Aug 29 15:46:23 volumio volumio[809]: info: CorePlayQueue::getTrack 7 Aug 29 15:46:23 volumio volumio[809]: info: CoreCommandRouter::servicePause Aug 29 15:46:23 volumio volumio[809]: info: Spotify Received pause Aug 29 15:46:23 volumio volumio[809]: SPOTIFY: SPOTIFY PAUSE Aug 29 15:46:23 volumio volumio[809]: SPOTIFY: {"status":"play","position":7,"title":"จำนน","artist":"NONT TANONT","album":"จำนน","albumart":"https://i.scdn.co/image/ab67616d0000b2736449901b3c0a16e51a24ebcc","uri":"spotify:track:5jj7yXcilVsZPpyYtmD28X","trackType":"spotify","codec":"ogg","seek":0,"duration":249,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":true,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Aug 29 15:46:23 volumio volumio[809]: info: Sending Spotify command to local API: /player/pause Aug 29 15:46:23 volumio go-librespot[1101]: time="2024-08-29T15:46:23+07:00" level=debug msg="pause track at 23462ms" Aug 29 15:46:23 volumio go-librespot[1101]: time="2024-08-29T15:46:23+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:46:24 volumio go-librespot[1101]: time="2024-08-29T15:46:24+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:46:24 volumio go-librespot[1101]: time="2024-08-29T15:46:24+07:00" level=trace msg="emitting websocket event: paused" Aug 29 15:46:24 volumio volumio[809]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5jj7yXcilVsZPpyYtmD28X","play_origin":"go-librespot"}} Aug 29 15:46:24 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Aug 29 15:46:24 volumio volumio[809]: SPOTIFY: {"status":"pause","service":"spop","title":"จำนน","artist":"NONT TANONT","album":"จำนน","albumart":"https://i.scdn.co/image/ab67616d00001e026449901b3c0a16e51a24ebcc","uri":"spotify:track:5jj7yXcilVsZPpyYtmD28X","trackType":"spotify","seek":23000,"duration":249,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:46:24 volumio volumio[809]: info: CoreCommandRouter::servicePushState Aug 29 15:46:24 volumio volumio[809]: info: CorePlayQueue::getTrack 7 Aug 29 15:46:24 volumio volumio[809]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"จำนน","artist":"NONT TANONT","album":"จำนน","albumart":"https://i.scdn.co/image/ab67616d00001e026449901b3c0a16e51a24ebcc","uri":"spotify:track:5jj7yXcilVsZPpyYtmD28X","trackType":"spotify","seek":23000,"duration":249,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:46:24 volumio volumio[809]: verbose: CURRENT POSITION 7 Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::syncState stateService pause Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus pause Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:46:24 volumio volumio[809]: info: CorePlayQueue::getTrack 7 Aug 29 15:46:24 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 15:46:24 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::stPlaybackTimer Aug 29 15:46:24 volumio volumio[809]: info: touch_display: Setting screensaver timeout to 15 seconds. Aug 29 15:46:24 volumio volumio[809]: info: CoreCommandRouter::volumioNext Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::next Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::stop Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::updateTrackBlock Aug 29 15:46:24 volumio volumio[809]: info: CorePlayQueue::getTrackBlock Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::stPlaybackTimer Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:46:24 volumio volumio[809]: info: CorePlayQueue::getTrack 7 Aug 29 15:46:24 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 15:46:24 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::serviceStop Aug 29 15:46:24 volumio volumio[809]: info: CorePlayQueue::getTrack 7 Aug 29 15:46:24 volumio volumio[809]: info: CoreCommandRouter::serviceStop Aug 29 15:46:24 volumio volumio[809]: info: Spotify Stop Aug 29 15:46:24 volumio volumio[809]: SPOTIFY: SPOTIFY STOP Aug 29 15:46:24 volumio volumio[809]: SPOTIFY: {"status":"pause","position":7,"title":"จำนน","artist":"NONT TANONT","album":"จำนน","albumart":"https://i.scdn.co/image/ab67616d0000b2736449901b3c0a16e51a24ebcc","uri":"spotify:track:5jj7yXcilVsZPpyYtmD28X","trackType":"spotify","codec":"ogg","seek":23806,"duration":249,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":true,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Aug 29 15:46:24 volumio volumio[809]: info: Sending Spotify command to local API: /player/pause Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::play index undefined Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:46:24 volumio volumio[809]: info: CorePlayQueue::getTrack 4 Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::startPlaybackTimer Aug 29 15:46:24 volumio volumio[809]: info: CorePlayQueue::getTrack 4 Aug 29 15:46:24 volumio volumio[809]: info: [1724921184405] ControllerSpotify::clearAddPlayTrack Aug 29 15:46:24 volumio volumio[809]: info: Sending Spotify command with payload to local API: /player/play Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::updateTrackBlock Aug 29 15:46:24 volumio volumio[809]: info: CorePlayQueue::getTrackBlock Aug 29 15:46:24 volumio go-librespot[1101]: time="2024-08-29T15:46:24+07:00" level=debug msg="pause track at 23961ms" Aug 29 15:46:24 volumio go-librespot[1101]: time="2024-08-29T15:46:24+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:46:24 volumio go-librespot[1101]: time="2024-08-29T15:46:24+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:46:24 volumio go-librespot[1101]: time="2024-08-29T15:46:24+07:00" level=trace msg="emitting websocket event: paused" Aug 29 15:46:24 volumio volumio[809]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5jj7yXcilVsZPpyYtmD28X","play_origin":"go-librespot"}} Aug 29 15:46:24 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Aug 29 15:46:24 volumio volumio[809]: 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} Aug 29 15:46:24 volumio volumio[809]: info: CoreCommandRouter::servicePushState Aug 29 15:46:24 volumio volumio[809]: info: CorePlayQueue::getTrack 4 Aug 29 15:46:24 volumio volumio[809]: 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} Aug 29 15:46:24 volumio volumio[809]: verbose: CURRENT POSITION 4 Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::syncState stateService pause Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus stop Aug 29 15:46:24 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:46:24 volumio volumio[809]: info: CorePlayQueue::getTrack 4 Aug 29 15:46:24 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 15:46:24 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:46:24 volumio go-librespot[1101]: time="2024-08-29T15:46:24+07:00" level=debug msg="resolved context of track" uri="spotify:track:1iB4DlhihIiLpXB6rTDtkO" Aug 29 15:46:24 volumio go-librespot[1101]: time="2024-08-29T15:46:24+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:1iB4DlhihIiLpXB6rTDtkO" Aug 29 15:46:24 volumio go-librespot[1101]: time="2024-08-29T15:46:24+07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:1iB4DlhihIiLpXB6rTDtkO" Aug 29 15:46:24 volumio go-librespot[1101]: time="2024-08-29T15:46:24+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:46:24 volumio go-librespot[1101]: time="2024-08-29T15:46:24+07:00" level=trace msg="emitting websocket event: will_play" Aug 29 15:46:24 volumio volumio[809]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:1iB4DlhihIiLpXB6rTDtkO","play_origin":"go-librespot"}} Aug 29 15:46:24 volumio go-librespot[1101]: time="2024-08-29T15:46:24+07:00" level=debug msg="selected format OGG_VORBIS_320 (ffc990e7e1332b6d66c8dc106e0c9fe5f397dc47)" uri="spotify:track:1iB4DlhihIiLpXB6rTDtkO" Aug 29 15:46:24 volumio go-librespot[1101]: time="2024-08-29T15:46:24+07:00" level=debug msg="requested aes key for file ffc990e7e1332b6d66c8dc106e0c9fe5f397dc47, gid: 1iB4DlhihIiLpXB6rTDtkO" Aug 29 15:46:25 volumio go-librespot[1101]: time="2024-08-29T15:46:25+07:00" level=debug msg="fetched first chunk of 14, total size is 7210427 bytes" uri="spotify:track:1iB4DlhihIiLpXB6rTDtkO" Aug 29 15:46:25 volumio go-librespot[1101]: time="2024-08-29T15:46:25+07:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:1iB4DlhihIiLpXB6rTDtkO" Aug 29 15:46:25 volumio go-librespot[1101]: time="2024-08-29T15:46:25+07:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Aug 29 15:46:25 volumio go-librespot[1101]: time="2024-08-29T15:46:25+07:00" level=info msg="loaded track \"เหนื่อยหน่อยนะ (SOMEONE LIKE ME)\" (paused: false, position: 0ms, duration: 176727ms, prefetched: false)" uri="spotify:track:1iB4DlhihIiLpXB6rTDtkO" Aug 29 15:46:25 volumio go-librespot[1101]: time="2024-08-29T15:46:25+07:00" level=debug msg="fetched chunk 1/13, size: 524288" uri="spotify:track:1iB4DlhihIiLpXB6rTDtkO" Aug 29 15:46:25 volumio go-librespot[1101]: time="2024-08-29T15:46:25+07:00" level=debug msg="fetched chunk 3/13, size: 524288" uri="spotify:track:1iB4DlhihIiLpXB6rTDtkO" Aug 29 15:46:25 volumio go-librespot[1101]: time="2024-08-29T15:46:25+07:00" level=debug msg="fetched chunk 2/13, size: 524288" uri="spotify:track:1iB4DlhihIiLpXB6rTDtkO" Aug 29 15:46:25 volumio go-librespot[1101]: time="2024-08-29T15:46:25+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:46:25 volumio go-librespot[1101]: time="2024-08-29T15:46:25+07:00" level=trace msg="scheduling prefetch in 147s" Aug 29 15:46:25 volumio go-librespot[1101]: time="2024-08-29T15:46:25+07:00" level=trace msg="emitting websocket event: metadata" Aug 29 15:46:25 volumio volumio[809]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:1iB4DlhihIiLpXB6rTDtkO","name":"เหนื่อยหน่อยนะ (SOMEONE LIKE ME)","artist_names":["GEMINI"],"album_name":"เหนื่อยหน่อยนะ (SOMEONE LIKE ME) - Single","album_cover_url":"https://i.scdn.co/image/ab67616d00001e027c2663207c72f68258bc4a88","position":0,"duration":176727,"release_date":"year:2024 month:8 day:15","track_number":1,"disc_number":1}} Aug 29 15:46:25 volumio go-librespot[1101]: time="2024-08-29T15:46:25+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:46:25 volumio go-librespot[1101]: time="2024-08-29T15:46:25+07:00" level=trace msg="emitting websocket event: playing" Aug 29 15:46:25 volumio volumio[809]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:1iB4DlhihIiLpXB6rTDtkO","play_origin":"go-librespot"}} Aug 29 15:46:25 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Aug 29 15:46:25 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"เหนื่อยหน่อยนะ (SOMEONE LIKE ME)","artist":"GEMINI","album":"เหนื่อยหน่อยนะ (SOMEONE LIKE ME) - Single","albumart":"https://i.scdn.co/image/ab67616d00001e027c2663207c72f68258bc4a88","uri":"spotify:track:1iB4DlhihIiLpXB6rTDtkO","trackType":"spotify","seek":0,"duration":176,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:46:25 volumio volumio[809]: info: CoreCommandRouter::servicePushState Aug 29 15:46:25 volumio volumio[809]: info: CorePlayQueue::getTrack 4 Aug 29 15:46:25 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"เหนื่อยหน่อยนะ (SOMEONE LIKE ME)","artist":"GEMINI","album":"เหนื่อยหน่อยนะ (SOMEONE LIKE ME) - Single","albumart":"https://i.scdn.co/image/ab67616d00001e027c2663207c72f68258bc4a88","uri":"spotify:track:1iB4DlhihIiLpXB6rTDtkO","trackType":"spotify","seek":0,"duration":176,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:46:25 volumio volumio[809]: verbose: CURRENT POSITION 4 Aug 29 15:46:25 volumio volumio[809]: info: CoreStateMachine::syncState stateService play Aug 29 15:46:25 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus stop Aug 29 15:46:25 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Aug 29 15:46:25 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"เหนื่อยหน่อยนะ (SOMEONE LIKE ME)","artist":"GEMINI","album":"เหนื่อยหน่อยนะ (SOMEONE LIKE ME) - Single","albumart":"https://i.scdn.co/image/ab67616d00001e027c2663207c72f68258bc4a88","uri":"spotify:track:1iB4DlhihIiLpXB6rTDtkO","trackType":"spotify","seek":0,"duration":176,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:46:25 volumio volumio[809]: info: CoreCommandRouter::servicePushState Aug 29 15:46:25 volumio volumio[809]: info: CorePlayQueue::getTrack 4 Aug 29 15:46:25 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"เหนื่อยหน่อยนะ (SOMEONE LIKE ME)","artist":"GEMINI","album":"เหนื่อยหน่อยนะ (SOMEONE LIKE ME) - Single","albumart":"https://i.scdn.co/image/ab67616d00001e027c2663207c72f68258bc4a88","uri":"spotify:track:1iB4DlhihIiLpXB6rTDtkO","trackType":"spotify","seek":0,"duration":176,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:46:25 volumio volumio[809]: verbose: CURRENT POSITION 4 Aug 29 15:46:25 volumio volumio[809]: info: CoreStateMachine::syncState stateService play Aug 29 15:46:25 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus play Aug 29 15:46:25 volumio volumio[809]: info: Received an update from plugin. extracting info from payload Aug 29 15:46:25 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:46:25 volumio volumio[809]: info: CorePlayQueue::getTrack 4 Aug 29 15:46:25 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 15:46:25 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:46:25 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:46:25 volumio volumio[809]: info: CorePlayQueue::getTrack 4 Aug 29 15:46:25 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:46:37 volumio go-librespot[1101]: time="2024-08-29T15:46:37+07:00" level=debug msg="fetched chunk 4/13, size: 524288" uri="spotify:track:1iB4DlhihIiLpXB6rTDtkO" Aug 29 15:46:45 volumio volumio[809]: info: Preload queue cleared Aug 29 15:46:45 volumio volumio[809]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::ClearQueue Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::stop Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::stPlaybackTimer Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::updateTrackBlock Aug 29 15:46:45 volumio volumio[809]: info: CorePlayQueue::getTrackBlock Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:46:45 volumio volumio[809]: info: CorePlayQueue::getTrack 4 Aug 29 15:46:45 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 15:46:45 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::serviceStop Aug 29 15:46:45 volumio volumio[809]: info: CorePlayQueue::getTrack 4 Aug 29 15:46:45 volumio volumio[809]: info: CoreCommandRouter::serviceStop Aug 29 15:46:45 volumio volumio[809]: info: Spotify Stop Aug 29 15:46:45 volumio volumio[809]: SPOTIFY: SPOTIFY STOP Aug 29 15:46:45 volumio volumio[809]: SPOTIFY: {"status":"play","position":4,"title":"เหนื่อยหน่อยนะ (SOMEONE LIKE ME)","artist":"GEMINI","album":"เหนื่อยหน่อยนะ (SOMEONE LIKE ME) - Single","albumart":"https://i.scdn.co/image/ab67616d0000b2737c2663207c72f68258bc4a88","uri":"spotify:track:1iB4DlhihIiLpXB6rTDtkO","trackType":"spotify","codec":"ogg","seek":0,"duration":176,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":true,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Aug 29 15:46:45 volumio volumio[809]: info: Sending Spotify command to local API: /player/pause Aug 29 15:46:45 volumio volumio[809]: info: CorePlayQueue::clearPlayQueue Aug 29 15:46:45 volumio volumio[809]: info: CorePlayQueue::saveQueue Aug 29 15:46:45 volumio volumio[809]: info: CoreCommandRouter::volumioPushQueue Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::addQueueItems Aug 29 15:46:45 volumio volumio[809]: info: CorePlayQueue::addQueueItems Aug 29 15:46:45 volumio volumio[809]: info: Preload queue cleared Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:7syPkLWA4AjH2jto6FDjEC Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:7syPkLWA4AjH2jto6FDjEC Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:4kE80JWRissrodmXuo0xYi Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:4kE80JWRissrodmXuo0xYi Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:2MuJCv3nCgHYlgOrAvCAT6 Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:2MuJCv3nCgHYlgOrAvCAT6 Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:2LJerOY5jSwO5K6OF9Cyuz Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:2LJerOY5jSwO5K6OF9Cyuz Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:1iB4DlhihIiLpXB6rTDtkO Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:1iB4DlhihIiLpXB6rTDtkO Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:5F4fAhzhdHtaQ8nNqWAufl Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:5F4fAhzhdHtaQ8nNqWAufl Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:08NGk13plUmQ5E5yjxIPIz Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:08NGk13plUmQ5E5yjxIPIz Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:5jj7yXcilVsZPpyYtmD28X Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:5jj7yXcilVsZPpyYtmD28X Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:7ykcQ6Jx9Q6JbLGAazWuKS Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:7ykcQ6Jx9Q6JbLGAazWuKS Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:25K1tGmiprhsC8LXgOrNjM Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:25K1tGmiprhsC8LXgOrNjM Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:3wyzSQ9rAWjx9vsMQSrLn2 Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:3wyzSQ9rAWjx9vsMQSrLn2 Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:6pTSm2Sw6fEEO4iKfOJqTL Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:6pTSm2Sw6fEEO4iKfOJqTL Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:2kpVbauiG7Tcue6kZPKYNG Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:2kpVbauiG7Tcue6kZPKYNG Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:0zLFNFvbnPmWZfDewtyaVg Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:0zLFNFvbnPmWZfDewtyaVg Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:2QV4JzbjMvgBRXsZHE0vW5 Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:2QV4JzbjMvgBRXsZHE0vW5 Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:759xYXTgNDGU6i6FH4kruy Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:759xYXTgNDGU6i6FH4kruy Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:2AdBbeVaEdW731a3FXJAJC Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:2AdBbeVaEdW731a3FXJAJC Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:5Ssjl0BJRFKtjxbgZlnoj9 Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:5Ssjl0BJRFKtjxbgZlnoj9 Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:6C66xbNCg6Zv19tisXJnUC Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:6C66xbNCg6Zv19tisXJnUC Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:31re0DMfO6aHU3FkCuJEoZ Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:31re0DMfO6aHU3FkCuJEoZ Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:2ayGJpuQFrTlIYVQ8iNPY8 Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:2ayGJpuQFrTlIYVQ8iNPY8 Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:6UuJgXnKGdAWeRwD8asDI3 Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:6UuJgXnKGdAWeRwD8asDI3 Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:79qhHPvit6BeOVu2wNnLgJ Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:79qhHPvit6BeOVu2wNnLgJ Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:5BmF05GWZpmm5JZ5p3yMJr Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:5BmF05GWZpmm5JZ5p3yMJr Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:6BqnE3hiqtywrLMJ3ulYDp Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:6BqnE3hiqtywrLMJ3ulYDp Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:7gPJ0LnpLQOhqH1Gx13cwv Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:7gPJ0LnpLQOhqH1Gx13cwv Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:43eS61ezviPc61XDu6tRYR Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:43eS61ezviPc61XDu6tRYR Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:28uUXmHx13AZ1nkl57vCwN Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:28uUXmHx13AZ1nkl57vCwN Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:3AC0O8MXujdSazZx1nOJK4 Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:3AC0O8MXujdSazZx1nOJK4 Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:36VP0QLf0R3KqcWeyJxuEO Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:36VP0QLf0R3KqcWeyJxuEO Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:5ARFnqIJJc9OgCRB7tEygC Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:5ARFnqIJJc9OgCRB7tEygC Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:6rk1rGqpNXTeu7kVsB049F Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:6rk1rGqpNXTeu7kVsB049F Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:7n8XxOyeEnGBNJ7u5ClhCn Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:7n8XxOyeEnGBNJ7u5ClhCn Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:1WbqdJzBawPmNVBL1tT7dK Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:1WbqdJzBawPmNVBL1tT7dK Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:56n3cbPJeypX5NyqgsmpnZ Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:56n3cbPJeypX5NyqgsmpnZ Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:13fTUwOsAtNtZtxAcBOtWy Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:13fTUwOsAtNtZtxAcBOtWy Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:1fUncVCIUnmf6qihsRkoBE Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:1fUncVCIUnmf6qihsRkoBE Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:4bnxMt1viexb85sAtVz1dA Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:4bnxMt1viexb85sAtVz1dA Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:42NFq86YCRMnV10M7lihzk Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:42NFq86YCRMnV10M7lihzk Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:1EOWBTE1GPKcxz3wlR08tW Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:1EOWBTE1GPKcxz3wlR08tW Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:2CjNvED1BSLPG1jYENA0QS Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:2CjNvED1BSLPG1jYENA0QS Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:30ho6wAl9w53sCtcqzHVMA Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:30ho6wAl9w53sCtcqzHVMA Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:0D9lpJts3mXxe0fvovYUFv Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:0D9lpJts3mXxe0fvovYUFv Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:56wDFSIa9Tr7zbEXUVMwjP Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:56wDFSIa9Tr7zbEXUVMwjP Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:3t1Ex6dp0O7tUP3NLyjAY8 Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:3t1Ex6dp0O7tUP3NLyjAY8 Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:1rNYuv63emsYt4Jjv8RlgJ Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:1rNYuv63emsYt4Jjv8RlgJ Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:62HLOpfjoG6E0JTtUEfplQ Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:62HLOpfjoG6E0JTtUEfplQ Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:6rgF7lJWhf0jR5ZEJk3cY5 Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:6rgF7lJWhf0jR5ZEJk3cY5 Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:2HC3jRQilGWyFlvICAqCaP Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:2HC3jRQilGWyFlvICAqCaP Aug 29 15:46:45 volumio volumio[809]: info: Adding Item to queue: spotify:track:4lYo2OzvdN3WCy7FQhHIv5 Aug 29 15:46:45 volumio volumio[809]: info: Using cached record of: spotify:track:4lYo2OzvdN3WCy7FQhHIv5 Aug 29 15:46:45 volumio volumio[809]: info: CoreCommandRouter::volumioPushQueue Aug 29 15:46:45 volumio volumio[809]: info: CorePlayQueue::saveQueue Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::updateTrackBlock Aug 29 15:46:45 volumio volumio[809]: info: CorePlayQueue::getTrackBlock Aug 29 15:46:45 volumio volumio[809]: info: CoreCommandRouter::volumioPlay Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::play index 3 Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::stop Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::play index undefined Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:46:45 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::startPlaybackTimer Aug 29 15:46:45 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:46:45 volumio volumio[809]: info: [1724921205668] ControllerSpotify::clearAddPlayTrack Aug 29 15:46:45 volumio volumio[809]: info: Sending Spotify command with payload to local API: /player/play Aug 29 15:46:45 volumio go-librespot[1101]: time="2024-08-29T15:46:45+07:00" level=debug msg="pause track at 20652ms" Aug 29 15:46:45 volumio volumio[809]: info: touch_display: Setting screensaver timeout to 15 seconds. Aug 29 15:46:45 volumio go-librespot[1101]: time="2024-08-29T15:46:45+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:46:45 volumio go-librespot[1101]: time="2024-08-29T15:46:45+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:46:45 volumio go-librespot[1101]: time="2024-08-29T15:46:45+07:00" level=trace msg="emitting websocket event: paused" Aug 29 15:46:45 volumio volumio[809]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:1iB4DlhihIiLpXB6rTDtkO","play_origin":"go-librespot"}} Aug 29 15:46:45 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Aug 29 15:46:45 volumio volumio[809]: 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} Aug 29 15:46:45 volumio volumio[809]: info: CoreCommandRouter::servicePushState Aug 29 15:46:45 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:46:45 volumio volumio[809]: 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} Aug 29 15:46:45 volumio volumio[809]: verbose: CURRENT POSITION 3 Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::syncState stateService pause Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus stop Aug 29 15:46:45 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:46:45 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:46:45 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 15:46:45 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=debug msg="resolved context of track" uri="spotify:track:2LJerOY5jSwO5K6OF9Cyuz" Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:2LJerOY5jSwO5K6OF9Cyuz" Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2LJerOY5jSwO5K6OF9Cyuz" Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=trace msg="emitting websocket event: will_play" Aug 29 15:46:46 volumio volumio[809]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2LJerOY5jSwO5K6OF9Cyuz","play_origin":"go-librespot"}} Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=debug msg="selected format OGG_VORBIS_320 (f5c89f6fdd98c5a971a5201cfe930bf5536cc1ca)" uri="spotify:track:2LJerOY5jSwO5K6OF9Cyuz" Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=debug msg="requested aes key for file f5c89f6fdd98c5a971a5201cfe930bf5536cc1ca, gid: 2LJerOY5jSwO5K6OF9Cyuz" Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=debug msg="fetched first chunk of 19, total size is 9827351 bytes" uri="spotify:track:2LJerOY5jSwO5K6OF9Cyuz" Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:2LJerOY5jSwO5K6OF9Cyuz" Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=debug msg="fetched chunk 3/18, size: 524288" uri="spotify:track:2LJerOY5jSwO5K6OF9Cyuz" Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=info msg="loaded track \"พบรัก\" (paused: false, position: 0ms, duration: 234000ms, prefetched: false)" uri="spotify:track:2LJerOY5jSwO5K6OF9Cyuz" Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=debug msg="fetched chunk 1/18, size: 524288" uri="spotify:track:2LJerOY5jSwO5K6OF9Cyuz" Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=debug msg="fetched chunk 2/18, size: 524288" uri="spotify:track:2LJerOY5jSwO5K6OF9Cyuz" Aug 29 15:46:46 volumio volumio[809]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Total Clients: 8 Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=trace msg="scheduling prefetch in 204s" Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=trace msg="emitting websocket event: metadata" Aug 29 15:46:46 volumio volumio[809]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2LJerOY5jSwO5K6OF9Cyuz","name":"พบรัก","artist_names":["Ink Waruntorn"],"album_name":"พบรัก","album_cover_url":"https://i.scdn.co/image/ab67616d00001e029fe49afc06c36334c06715f7","position":0,"duration":234000,"release_date":"year:2024 month:6 day:20","track_number":1,"disc_number":1}} Aug 29 15:46:46 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Aug 29 15:46:46 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:46:46 volumio go-librespot[1101]: time="2024-08-29T15:46:46+07:00" level=trace msg="emitting websocket event: playing" Aug 29 15:46:46 volumio volumio[809]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:2LJerOY5jSwO5K6OF9Cyuz","play_origin":"go-librespot"}} Aug 29 15:46:46 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Aug 29 15:46:46 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"พบรัก","artist":"Ink Waruntorn","album":"พบรัก","albumart":"https://i.scdn.co/image/ab67616d00001e029fe49afc06c36334c06715f7","uri":"spotify:track:2LJerOY5jSwO5K6OF9Cyuz","trackType":"spotify","seek":0,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:46:46 volumio volumio[809]: info: CoreCommandRouter::servicePushState Aug 29 15:46:46 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:46:46 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"พบรัก","artist":"Ink Waruntorn","album":"พบรัก","albumart":"https://i.scdn.co/image/ab67616d00001e029fe49afc06c36334c06715f7","uri":"spotify:track:2LJerOY5jSwO5K6OF9Cyuz","trackType":"spotify","seek":0,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:46:46 volumio volumio[809]: verbose: CURRENT POSITION 3 Aug 29 15:46:46 volumio volumio[809]: info: CoreStateMachine::syncState stateService play Aug 29 15:46:46 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus stop Aug 29 15:46:47 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Aug 29 15:46:47 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"พบรัก","artist":"Ink Waruntorn","album":"พบรัก","albumart":"https://i.scdn.co/image/ab67616d00001e029fe49afc06c36334c06715f7","uri":"spotify:track:2LJerOY5jSwO5K6OF9Cyuz","trackType":"spotify","seek":0,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:46:47 volumio volumio[809]: info: CoreCommandRouter::servicePushState Aug 29 15:46:47 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:46:47 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"พบรัก","artist":"Ink Waruntorn","album":"พบรัก","albumart":"https://i.scdn.co/image/ab67616d00001e029fe49afc06c36334c06715f7","uri":"spotify:track:2LJerOY5jSwO5K6OF9Cyuz","trackType":"spotify","seek":0,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:46:47 volumio volumio[809]: verbose: CURRENT POSITION 3 Aug 29 15:46:47 volumio volumio[809]: info: CoreStateMachine::syncState stateService play Aug 29 15:46:47 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus play Aug 29 15:46:47 volumio volumio[809]: info: Received an update from plugin. extracting info from payload Aug 29 15:46:47 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:46:47 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:46:47 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 15:46:47 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:46:47 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:46:47 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:46:47 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:46:49 volumio volumio[809]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Total Clients: 9 Aug 29 15:46:49 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Aug 29 15:46:49 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:46:49 volumio nmbd[749]: [2024/08/29 15:46:49.569844, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Aug 29 15:46:49 volumio nmbd[749]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.1.7 for name WORKGROUP<1d>. Aug 29 15:46:49 volumio nmbd[749]: This response was from IP 192.168.1.250, reporting an IP address of 192.168.1.250. Aug 29 15:46:53 volumio volumio[809]: info: peppy_screensaver: Start PeppyMeter Aug 29 15:46:55 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Aug 29 15:46:55 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:46:56 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 15:46:56 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 29 15:46:58 volumio go-librespot[1101]: time="2024-08-29T15:46:58+07:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Aug 29 15:46:58 volumio volumio[809]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Aug 29 15:46:58 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 15:46:58 volumio volumio[809]: info: Disabling plugin spop Aug 29 15:46:58 volumio sudo[2394]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service Aug 29 15:46:58 volumio volumio[809]: info: Done. Aug 29 15:46:58 volumio sudo[2394]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 15:46:58 volumio volumio[809]: info: Connection to go-librespot Websocket closed Aug 29 15:46:58 volumio systemd[1]: Stopping go-librespot Daemon... Aug 29 15:46:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Aug 29 15:46:58 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Aug 29 15:46:58 volumio systemd[1]: Stopped go-librespot Daemon. Aug 29 15:46:58 volumio sudo[2394]: pam_unix(sudo:session): session closed for user root Aug 29 15:47:01 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Aug 29 15:47:01 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:47:02 volumio volumio[809]: info: CoreCommandRouter::volumioClearQueue Aug 29 15:47:02 volumio volumio[809]: info: CoreStateMachine::ClearQueue Aug 29 15:47:02 volumio volumio[809]: info: CoreStateMachine::stop Aug 29 15:47:02 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:47:02 volumio volumio[809]: info: CoreStateMachine::stPlaybackTimer Aug 29 15:47:02 volumio volumio[809]: info: CoreStateMachine::updateTrackBlock Aug 29 15:47:02 volumio volumio[809]: info: CorePlayQueue::getTrackBlock Aug 29 15:47:02 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:47:02 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:47:02 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 15:47:02 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:47:02 volumio volumio[809]: info: CoreStateMachine::serviceStop Aug 29 15:47:02 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:47:02 volumio volumio[809]: info: CoreCommandRouter::serviceStop Aug 29 15:47:02 volumio volumio[809]: error: WARNING: No stop method for service spop Aug 29 15:47:02 volumio volumio[809]: info: CorePlayQueue::clearPlayQueue Aug 29 15:47:02 volumio volumio[809]: info: CorePlayQueue::saveQueue Aug 29 15:47:02 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:47:02 volumio volumio[809]: info: CoreCommandRouter::volumioPushQueue Aug 29 15:47:02 volumio volumio[809]: info: touch_display: Setting screensaver timeout to 15 seconds. Aug 29 15:47:04 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Aug 29 15:47:04 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:47:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 15:47:05 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 29 15:47:06 volumio volumio[809]: info: Enabling plugin spop Aug 29 15:47:06 volumio volumio[809]: info: Loading plugin "spop"... Aug 29 15:47:06 volumio volumio[809]: info: PLUGIN START: spop Aug 29 15:47:06 volumio volumio[809]: info: Creating Spotify config file Aug 29 15:47:06 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 29 15:47:06 volumio volumio[809]: info: Done. Aug 29 15:47:06 volumio volumio[809]: info: Spotify config file written Aug 29 15:47:06 volumio sudo[2399]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Aug 29 15:47:06 volumio sudo[2399]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 15:47:07 volumio systemd[1]: Started go-librespot Daemon. Aug 29 15:47:07 volumio go-librespot[2401]: Librespot-go daemon starting... Aug 29 15:47:07 volumio sudo[2399]: pam_unix(sudo:session): session closed for user root Aug 29 15:47:07 volumio go-librespot[2401]: time="2024-08-29T15:47:07+07:00" level=info msg="generated new device id: af303056dc94f317a159cb7942e9321a803be7d3" Aug 29 15:47:07 volumio go-librespot[2401]: time="2024-08-29T15:47:07+07:00" level=debug msg="stored credentials found for 31vgyg6ayig6ixborxqh2dp5mx6a" Aug 29 15:47:07 volumio volumio[809]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Aug 29 15:47:07 volumio volumio[809]: SPOTIFY: BQB1N1yMqDk-iRJXJCXRGaa3tyteuLFw3UXcjkOTXbuXXNGVLDGGI2nPACYp59faGbr-oK_veBsrbCbolbkpYLbBphAA_a6Hw8wKH1tFUPp8V20jl71B5LhSbePWYGcjlGQG-JWQq3dOtuVhY94GLsjsfiy89wdVSpXoo3N3tZt4WFZ7IzLLdrqr8iJrmwBLo9A8xUuNFR0ZAN6WXihMVZAJbSAajornFFUburaTaamNJqiqa8MoBL1juSTRWdgYJAlhv9L1p43STMOn59o Aug 29 15:47:07 volumio volumio[809]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Aug 29 15:47:07 volumio volumio[809]: info: New Spotify access token = BQB1N1yMqDk-iRJXJCXRGaa3tyteuLFw3UXcjkOTXbuXXNGVLDGGI2nPACYp59faGbr-oK_veBsrbCbolbkpYLbBphAA_a6Hw8wKH1tFUPp8V20jl71B5LhSbePWYGcjlGQG-JWQq3dOtuVhY94GLsjsfiy89wdVSpXoo3N3tZt4WFZ7IzLLdrqr8iJrmwBLo9A8xUuNFR0ZAN6WXihMVZAJbSAajornFFUburaTaamNJqiqa8MoBL1juSTRWdgYJAlhv9L1p43STMOn59o Aug 29 15:47:07 volumio volumio[809]: info: Spotify credentials grant success - running version from March 24, 2019 Aug 29 15:47:07 volumio go-librespot[2401]: time="2024-08-29T15:47:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Aug 29 15:47:07 volumio go-librespot[2401]: time="2024-08-29T15:47:07+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Aug 29 15:47:07 volumio go-librespot[2401]: time="2024-08-29T15:47:07+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Aug 29 15:47:07 volumio go-librespot[2401]: time="2024-08-29T15:47:07+07:00" level=debug msg="zeroconf server listening on port 43409" Aug 29 15:47:07 volumio volumio[809]: SPOTIFY: User informations: {"display_name":"Prasong Rattanapongchinda","external_urls":{"spotify":"https://open.spotify.com/user/31vgyg6ayig6ixborxqh2dp5mx6a"},"href":"https://api.spotify.com/v1/users/31vgyg6ayig6ixborxqh2dp5mx6a","id":"31vgyg6ayig6ixborxqh2dp5mx6a","images":[{"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=2325259594171988&height=50&width=50&ext=1727492805&hash=Aba4-RY9R1Ig0C0zU1FhcNjw","height":64,"width":64},{"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=2325259594171988&height=300&width=300&ext=1727492805&hash=AbbaKtzHaw0FWokw2Q8MjNTk","height":300,"width":300}],"type":"user","uri":"spotify:user:31vgyg6ayig6ixborxqh2dp5mx6a","followers":{"href":null,"total":0},"country":"TH","product":"premium","explicit_content":{"filter_enabled":false,"filter_locked":false},"email":"nid_79@hotmail.com"} Aug 29 15:47:07 volumio volumio[809]: info: Spotify Successfully logged in Aug 29 15:47:07 volumio volumio[809]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 29 15:47:07 volumio volumio[809]: info: [1724921227462] CoreMusicLibrary::Adding element Spotify Aug 29 15:47:07 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 15:47:07 volumio volumio[809]: Cannot find translation for source Spotify Aug 29 15:47:07 volumio go-librespot[2401]: time="2024-08-29T15:47:07+07:00" level=debug msg="obtained new client token: AAC87FjmHUEuOEoBMC49/SXlIQvjEIAUlRdgkTditk3v56EjsTppBLdXGHgxKy3vMShcL9Kzj/ywUQwrRQtwJdiziNH8pkxArzBFMmUajNqUA3ra8rLApJlVQUeg2zhoiMCxGIZJ2m9IH4jS7r9ayNxC1GRRHSB7BvGW4S6BghxTIpMi0cMiBFOyfNaae6CvAD6vRPuf7TizLOzB0hJt8cmRe1CKlFtPfQybDW2rXQ1zaoC3dK3bRow/Rw==" Aug 29 15:47:07 volumio go-librespot[2401]: time="2024-08-29T15:47:07+07:00" level=debug msg="completed keyexchange" Aug 29 15:47:08 volumio go-librespot[2401]: time="2024-08-29T15:47:08+07:00" level=debug msg="completed challenge" Aug 29 15:47:08 volumio go-librespot[2401]: time="2024-08-29T15:47:08+07:00" level=debug msg="authenticated as 31vgyg6ayig6ixborxqh2dp5mx6a" Aug 29 15:47:08 volumio go-librespot[2401]: time="2024-08-29T15:47:08+07:00" level=debug msg="authenticated as 31vgyg6ayig6ixborxqh2dp5mx6a" Aug 29 15:47:08 volumio go-librespot[2401]: time="2024-08-29T15:47:08+07:00" level=debug msg="dealer connection opened" Aug 29 15:47:08 volumio go-librespot[2401]: time="2024-08-29T15:47:08+07:00" level=debug msg="initializing zeroconf session, username: 31vgyg6ayig6ixborxqh2dp5mx6a" Aug 29 15:47:08 volumio go-librespot[2401]: time="2024-08-29T15:47:08+07:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Aug 29 15:47:08 volumio go-librespot[2401]: time="2024-08-29T15:47:08+07:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Aug 29 15:47:08 volumio go-librespot[2401]: time="2024-08-29T15:47:08+07:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Aug 29 15:47:08 volumio go-librespot[2401]: time="2024-08-29T15:47:08+07:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Aug 29 15:47:08 volumio go-librespot[2401]: time="2024-08-29T15:47:08+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Aug 29 15:47:08 volumio go-librespot[2401]: time="2024-08-29T15:47:08+07:00" level=debug msg="autoplay enabled: false" Aug 29 15:47:08 volumio go-librespot[2401]: time="2024-08-29T15:47:08+07:00" level=debug msg="received connection id: YmNkMDk1ODgtOTNkMC00NTFmLWEwNDQtNzc4N2M1MzkzMDZmK2RlYWxlcit0Y3A6Ly8wYWM5NDkyMC5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArNTMyOTFGOTFDRkQ3QTI4REJBRDBEQTBEN0E5NDdGNDVGODE5RDExOTlEMTNDOUIwQzVEMzMxQkZCRDU1NEE0Rg==" Aug 29 15:47:08 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Aug 29 15:47:08 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:47:08 volumio go-librespot[2401]: time="2024-08-29T15:47:08+07:00" level=debug msg="put connect state because NEW_DEVICE" Aug 29 15:47:10 volumio volumio[809]: info: go-librespot daemon successfully initialized Aug 29 15:47:13 volumio volumio[809]: info: Initializing connection to go-librespot Websocket Aug 29 15:47:13 volumio go-librespot[2401]: time="2024-08-29T15:47:13+07:00" level=debug msg="new websocket client" Aug 29 15:47:13 volumio volumio[809]: info: Connection to go-librespot Websocket established Aug 29 15:47:16 volumio volumio[809]: info: Getting Spotify volume Aug 29 15:47:16 volumio volumio[809]: info: Spotify volume: 100 Aug 29 15:47:16 volumio volumio[809]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Aug 29 15:47:16 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Aug 29 15:47:16 volumio volumio[809]: info: CorePlayQueue::getTrack 3 Aug 29 15:47:18 volumio volumio[809]: info: Preload queue cleared Aug 29 15:47:18 volumio volumio[809]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 29 15:47:18 volumio volumio[809]: info: CoreStateMachine::ClearQueue Aug 29 15:47:18 volumio volumio[809]: info: CoreStateMachine::stop Aug 29 15:47:18 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:47:18 volumio volumio[809]: info: CorePlayQueue::clearPlayQueue Aug 29 15:47:18 volumio volumio[809]: info: CorePlayQueue::saveQueue Aug 29 15:47:18 volumio volumio[809]: info: CoreCommandRouter::volumioPushQueue Aug 29 15:47:18 volumio volumio[809]: info: CoreStateMachine::addQueueItems Aug 29 15:47:18 volumio volumio[809]: info: CorePlayQueue::addQueueItems Aug 29 15:47:18 volumio volumio[809]: info: Preload queue cleared Aug 29 15:47:18 volumio volumio[809]: info: Adding Item to queue: spotify:playlist:37i9dQZF1DWW1S2VXZ4bIj Aug 29 15:47:18 volumio volumio[809]: info: Exploding uri spotify:playlist:37i9dQZF1DWW1S2VXZ4bIj in service spop Aug 29 15:47:18 volumio volumio[809]: SPOTIFY: EXPLODING URI:spotify:playlist:37i9dQZF1DWW1S2VXZ4bIj Aug 29 15:47:19 volumio volumio[809]: info: Preload queue cleared Aug 29 15:47:19 volumio volumio[809]: info: CoreCommandRouter::volumioReplaceandPlayItems Aug 29 15:47:19 volumio volumio[809]: info: CoreStateMachine::ClearQueue Aug 29 15:47:19 volumio volumio[809]: info: CoreStateMachine::stop Aug 29 15:47:19 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:47:19 volumio volumio[809]: info: CorePlayQueue::clearPlayQueue Aug 29 15:47:19 volumio volumio[809]: info: CorePlayQueue::saveQueue Aug 29 15:47:19 volumio volumio[809]: info: CoreCommandRouter::volumioPushQueue Aug 29 15:47:19 volumio volumio[809]: info: CoreStateMachine::addQueueItems Aug 29 15:47:19 volumio volumio[809]: info: CorePlayQueue::addQueueItems Aug 29 15:47:19 volumio volumio[809]: info: Preload queue cleared Aug 29 15:47:19 volumio volumio[809]: info: Adding Item to queue: spotify:playlist:37i9dQZF1DWW1S2VXZ4bIj Aug 29 15:47:19 volumio volumio[809]: info: Exploding uri spotify:playlist:37i9dQZF1DWW1S2VXZ4bIj in service spop Aug 29 15:47:19 volumio volumio[809]: SPOTIFY: EXPLODING URI:spotify:playlist:37i9dQZF1DWW1S2VXZ4bIj Aug 29 15:47:19 volumio volumio[809]: info: CoreCommandRouter::volumioPushQueue Aug 29 15:47:19 volumio volumio[809]: info: CorePlayQueue::saveQueue Aug 29 15:47:19 volumio volumio[809]: info: CoreStateMachine::updateTrackBlock Aug 29 15:47:19 volumio volumio[809]: info: CorePlayQueue::getTrackBlock Aug 29 15:47:19 volumio volumio[809]: info: CoreCommandRouter::volumioPlay Aug 29 15:47:19 volumio volumio[809]: info: CoreStateMachine::play index 0 Aug 29 15:47:19 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:47:19 volumio volumio[809]: info: CoreStateMachine::stop Aug 29 15:47:19 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:47:19 volumio volumio[809]: info: CoreStateMachine::play index undefined Aug 29 15:47:19 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:47:19 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:19 volumio volumio[809]: info: CoreStateMachine::startPlaybackTimer Aug 29 15:47:19 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:19 volumio volumio[809]: info: [1724921239904] ControllerSpotify::clearAddPlayTrack Aug 29 15:47:19 volumio volumio[809]: info: Sending Spotify command with payload to local API: /player/play Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="resolved context of track" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=trace msg="emitting websocket event: will_play" Aug 29 15:47:20 volumio volumio[809]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7syPkLWA4AjH2jto6FDjEC","play_origin":"go-librespot"}} Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1505" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="selected format OGG_VORBIS_320 (201e40dcbe847005036cd7804a1bdf64c15f3758)" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="requested aes key for file 201e40dcbe847005036cd7804a1bdf64c15f3758, gid: 7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="fetched first chunk of 20, total size is 10167008 bytes" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:20 volumio volumio[809]: info: CoreCommandRouter::volumioPushQueue Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:20 volumio volumio[809]: info: CorePlayQueue::saveQueue Aug 29 15:47:20 volumio volumio[809]: info: CoreStateMachine::updateTrackBlock Aug 29 15:47:20 volumio volumio[809]: info: CorePlayQueue::getTrackBlock Aug 29 15:47:20 volumio volumio[809]: info: CoreCommandRouter::volumioPlay Aug 29 15:47:20 volumio volumio[809]: info: CoreStateMachine::play index 0 Aug 29 15:47:20 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:47:20 volumio volumio[809]: info: CoreStateMachine::stop Aug 29 15:47:20 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:47:20 volumio volumio[809]: info: CoreStateMachine::play index undefined Aug 29 15:47:20 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:47:20 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:20 volumio volumio[809]: info: CoreStateMachine::startPlaybackTimer Aug 29 15:47:20 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:20 volumio volumio[809]: info: [1724921240532] ControllerSpotify::clearAddPlayTrack Aug 29 15:47:20 volumio volumio[809]: info: Sending Spotify command with payload to local API: /player/play Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="created new output device" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=info msg="loaded track \"DAY ONE\" (paused: false, position: 0ms, duration: 272700ms, prefetched: false)" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:20 volumio kernel: bcm2835-i2s fe203000.i2s: I2S SYNC error! Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=trace msg="scheduling prefetch in 242s" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=trace msg="emitting websocket event: metadata" Aug 29 15:47:20 volumio volumio[809]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7syPkLWA4AjH2jto6FDjEC","name":"DAY ONE","artist_names":["PUN"],"album_name":"DAY ONE","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0253f71dc84be19f1788c3a8ee","position":0,"duration":272700,"release_date":"year:2024 month:6 day:6","track_number":1,"disc_number":1}} Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="resolved context of track" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=trace msg="emitting websocket event: will_play" Aug 29 15:47:20 volumio volumio[809]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:7syPkLWA4AjH2jto6FDjEC","play_origin":"go-librespot"}} Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="selected format OGG_VORBIS_320 (201e40dcbe847005036cd7804a1bdf64c15f3758)" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:20 volumio go-librespot[2401]: time="2024-08-29T15:47:20+07:00" level=debug msg="requested aes key for file 201e40dcbe847005036cd7804a1bdf64c15f3758, gid: 7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:21 volumio go-librespot[2401]: time="2024-08-29T15:47:21+07:00" level=debug msg="fetched first chunk of 20, total size is 10167008 bytes" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:21 volumio go-librespot[2401]: time="2024-08-29T15:47:21+07:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:21 volumio go-librespot[2401]: time="2024-08-29T15:47:21+07:00" level=info msg="loaded track \"DAY ONE\" (paused: false, position: 0ms, duration: 272700ms, prefetched: false)" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:21 volumio go-librespot[2401]: time="2024-08-29T15:47:21+07:00" level=debug msg="fetched chunk 1/19, size: 524288" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:21 volumio go-librespot[2401]: time="2024-08-29T15:47:21+07:00" level=debug msg="fetched chunk 3/19, size: 524288" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:21 volumio go-librespot[2401]: time="2024-08-29T15:47:21+07:00" level=debug msg="fetched chunk 2/19, size: 524288" uri="spotify:track:7syPkLWA4AjH2jto6FDjEC" Aug 29 15:47:21 volumio go-librespot[2401]: time="2024-08-29T15:47:21+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:47:21 volumio go-librespot[2401]: time="2024-08-29T15:47:21+07:00" level=trace msg="scheduling prefetch in 242s" Aug 29 15:47:21 volumio go-librespot[2401]: time="2024-08-29T15:47:21+07:00" level=trace msg="emitting websocket event: metadata" Aug 29 15:47:21 volumio volumio[809]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:7syPkLWA4AjH2jto6FDjEC","name":"DAY ONE","artist_names":["PUN"],"album_name":"DAY ONE","album_cover_url":"https://i.scdn.co/image/ab67616d00001e0253f71dc84be19f1788c3a8ee","position":0,"duration":272700,"release_date":"year:2024 month:6 day:6","track_number":1,"disc_number":1}} Aug 29 15:47:21 volumio go-librespot[2401]: time="2024-08-29T15:47:21+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:47:21 volumio go-librespot[2401]: time="2024-08-29T15:47:21+07:00" level=trace msg="emitting websocket event: playing" Aug 29 15:47:21 volumio volumio[809]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7syPkLWA4AjH2jto6FDjEC","play_origin":"go-librespot"}} Aug 29 15:47:21 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Aug 29 15:47:21 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"DAY ONE","artist":"PUN","album":"DAY ONE","albumart":"https://i.scdn.co/image/ab67616d00001e0253f71dc84be19f1788c3a8ee","uri":"spotify:track:7syPkLWA4AjH2jto6FDjEC","trackType":"spotify","seek":0,"duration":272,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:47:21 volumio volumio[809]: info: CoreCommandRouter::servicePushState Aug 29 15:47:21 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:21 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"DAY ONE","artist":"PUN","album":"DAY ONE","albumart":"https://i.scdn.co/image/ab67616d00001e0253f71dc84be19f1788c3a8ee","uri":"spotify:track:7syPkLWA4AjH2jto6FDjEC","trackType":"spotify","seek":0,"duration":272,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:47:21 volumio volumio[809]: verbose: CURRENT POSITION 0 Aug 29 15:47:21 volumio volumio[809]: info: CoreStateMachine::syncState stateService play Aug 29 15:47:21 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus stop Aug 29 15:47:21 volumio go-librespot[2401]: time="2024-08-29T15:47:21+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:47:21 volumio go-librespot[2401]: time="2024-08-29T15:47:21+07:00" level=trace msg="emitting websocket event: playing" Aug 29 15:47:21 volumio volumio[809]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:7syPkLWA4AjH2jto6FDjEC","play_origin":"go-librespot"}} Aug 29 15:47:21 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Aug 29 15:47:21 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"DAY ONE","artist":"PUN","album":"DAY ONE","albumart":"https://i.scdn.co/image/ab67616d00001e0253f71dc84be19f1788c3a8ee","uri":"spotify:track:7syPkLWA4AjH2jto6FDjEC","trackType":"spotify","seek":0,"duration":272,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:47:21 volumio volumio[809]: info: CoreCommandRouter::servicePushState Aug 29 15:47:21 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:21 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"DAY ONE","artist":"PUN","album":"DAY ONE","albumart":"https://i.scdn.co/image/ab67616d00001e0253f71dc84be19f1788c3a8ee","uri":"spotify:track:7syPkLWA4AjH2jto6FDjEC","trackType":"spotify","seek":0,"duration":272,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:47:21 volumio volumio[809]: verbose: CURRENT POSITION 0 Aug 29 15:47:21 volumio volumio[809]: info: CoreStateMachine::syncState stateService play Aug 29 15:47:21 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus play Aug 29 15:47:21 volumio volumio[809]: info: Received an update from plugin. extracting info from payload Aug 29 15:47:21 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:47:21 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:21 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 15:47:21 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:47:21 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:47:21 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:21 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:47:21 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Aug 29 15:47:21 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"DAY ONE","artist":"PUN","album":"DAY ONE","albumart":"https://i.scdn.co/image/ab67616d00001e0253f71dc84be19f1788c3a8ee","uri":"spotify:track:7syPkLWA4AjH2jto6FDjEC","trackType":"spotify","seek":0,"duration":272,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:47:21 volumio volumio[809]: info: CoreCommandRouter::servicePushState Aug 29 15:47:21 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:21 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"DAY ONE","artist":"PUN","album":"DAY ONE","albumart":"https://i.scdn.co/image/ab67616d00001e0253f71dc84be19f1788c3a8ee","uri":"spotify:track:7syPkLWA4AjH2jto6FDjEC","trackType":"spotify","seek":0,"duration":272,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:47:21 volumio volumio[809]: verbose: CURRENT POSITION 0 Aug 29 15:47:21 volumio volumio[809]: info: CoreStateMachine::syncState stateService play Aug 29 15:47:21 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus play Aug 29 15:47:21 volumio volumio[809]: info: Received an update from plugin. extracting info from payload Aug 29 15:47:21 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:47:21 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:21 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:47:21 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:47:21 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:21 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:47:21 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Aug 29 15:47:21 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"DAY ONE","artist":"PUN","album":"DAY ONE","albumart":"https://i.scdn.co/image/ab67616d00001e0253f71dc84be19f1788c3a8ee","uri":"spotify:track:7syPkLWA4AjH2jto6FDjEC","trackType":"spotify","seek":0,"duration":272,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:47:21 volumio volumio[809]: info: CoreCommandRouter::servicePushState Aug 29 15:47:21 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:21 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"DAY ONE","artist":"PUN","album":"DAY ONE","albumart":"https://i.scdn.co/image/ab67616d00001e0253f71dc84be19f1788c3a8ee","uri":"spotify:track:7syPkLWA4AjH2jto6FDjEC","trackType":"spotify","seek":0,"duration":272,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:47:21 volumio volumio[809]: verbose: CURRENT POSITION 0 Aug 29 15:47:21 volumio volumio[809]: info: CoreStateMachine::syncState stateService play Aug 29 15:47:21 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus play Aug 29 15:47:21 volumio volumio[809]: info: Received an update from plugin. extracting info from payload Aug 29 15:47:21 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:47:21 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:21 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:47:21 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:47:21 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:21 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:47:32 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Aug 29 15:47:32 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:34 volumio volumio[809]: info: CoreCommandRouter::volumioNext Aug 29 15:47:34 volumio volumio[809]: info: CoreStateMachine::next Aug 29 15:47:34 volumio volumio[809]: info: CoreStateMachine::stop Aug 29 15:47:34 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:47:34 volumio volumio[809]: info: CoreStateMachine::stPlaybackTimer Aug 29 15:47:34 volumio volumio[809]: info: CoreStateMachine::updateTrackBlock Aug 29 15:47:34 volumio volumio[809]: info: CorePlayQueue::getTrackBlock Aug 29 15:47:34 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:47:34 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:34 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 15:47:34 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:47:34 volumio volumio[809]: info: CoreStateMachine::serviceStop Aug 29 15:47:34 volumio volumio[809]: info: CorePlayQueue::getTrack 0 Aug 29 15:47:34 volumio volumio[809]: info: CoreCommandRouter::serviceStop Aug 29 15:47:34 volumio volumio[809]: info: Spotify Stop Aug 29 15:47:34 volumio volumio[809]: SPOTIFY: SPOTIFY STOP Aug 29 15:47:34 volumio volumio[809]: SPOTIFY: {"status":"play","position":0,"title":"DAY ONE","artist":"PUN","album":"DAY ONE","albumart":"https://i.scdn.co/image/ab67616d0000b27353f71dc84be19f1788c3a8ee","uri":"spotify:track:7syPkLWA4AjH2jto6FDjEC","trackType":"spotify","codec":"ogg","seek":0,"duration":272,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":true,"repeat":true,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Aug 29 15:47:34 volumio volumio[809]: info: Sending Spotify command to local API: /player/pause Aug 29 15:47:34 volumio volumio[809]: info: CoreStateMachine::play index undefined Aug 29 15:47:34 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:47:34 volumio volumio[809]: info: CorePlayQueue::getTrack 97 Aug 29 15:47:34 volumio volumio[809]: info: CoreStateMachine::startPlaybackTimer Aug 29 15:47:34 volumio volumio[809]: info: CorePlayQueue::getTrack 97 Aug 29 15:47:34 volumio volumio[809]: info: [1724921254554] ControllerSpotify::clearAddPlayTrack Aug 29 15:47:34 volumio volumio[809]: info: Sending Spotify command with payload to local API: /player/play Aug 29 15:47:34 volumio volumio[809]: info: CoreStateMachine::updateTrackBlock Aug 29 15:47:34 volumio volumio[809]: info: CorePlayQueue::getTrackBlock Aug 29 15:47:34 volumio go-librespot[2401]: time="2024-08-29T15:47:34+07:00" level=debug msg="pause track at 13521ms" Aug 29 15:47:34 volumio volumio[809]: info: touch_display: Setting screensaver timeout to 15 seconds. Aug 29 15:47:34 volumio go-librespot[2401]: time="2024-08-29T15:47:34+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:47:34 volumio go-librespot[2401]: time="2024-08-29T15:47:34+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:47:34 volumio go-librespot[2401]: time="2024-08-29T15:47:34+07:00" level=trace msg="emitting websocket event: paused" Aug 29 15:47:34 volumio volumio[809]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:7syPkLWA4AjH2jto6FDjEC","play_origin":"go-librespot"}} Aug 29 15:47:34 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Aug 29 15:47:34 volumio volumio[809]: 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} Aug 29 15:47:34 volumio volumio[809]: info: CoreCommandRouter::servicePushState Aug 29 15:47:34 volumio volumio[809]: info: CorePlayQueue::getTrack 97 Aug 29 15:47:34 volumio volumio[809]: 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} Aug 29 15:47:34 volumio volumio[809]: verbose: CURRENT POSITION 97 Aug 29 15:47:34 volumio volumio[809]: info: CoreStateMachine::syncState stateService pause Aug 29 15:47:34 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus stop Aug 29 15:47:34 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:47:34 volumio volumio[809]: info: CorePlayQueue::getTrack 97 Aug 29 15:47:34 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 15:47:34 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:47:34 volumio go-librespot[2401]: time="2024-08-29T15:47:34+07:00" level=debug msg="resolved context of track" uri="spotify:track:4rWdiOhPQVk4vKff04obZl" Aug 29 15:47:34 volumio go-librespot[2401]: time="2024-08-29T15:47:34+07:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:4rWdiOhPQVk4vKff04obZl" Aug 29 15:47:34 volumio go-librespot[2401]: time="2024-08-29T15:47:34+07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:4rWdiOhPQVk4vKff04obZl" Aug 29 15:47:35 volumio go-librespot[2401]: time="2024-08-29T15:47:35+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:47:35 volumio go-librespot[2401]: time="2024-08-29T15:47:35+07:00" level=trace msg="emitting websocket event: will_play" Aug 29 15:47:35 volumio volumio[809]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4rWdiOhPQVk4vKff04obZl","play_origin":"go-librespot"}} Aug 29 15:47:35 volumio go-librespot[2401]: time="2024-08-29T15:47:35+07:00" level=debug msg="selected format OGG_VORBIS_320 (88a6e63ae7aa387363f7e419ba912570d48e877d)" uri="spotify:track:4rWdiOhPQVk4vKff04obZl" Aug 29 15:47:35 volumio go-librespot[2401]: time="2024-08-29T15:47:35+07:00" level=debug msg="requested aes key for file 88a6e63ae7aa387363f7e419ba912570d48e877d, gid: 4rWdiOhPQVk4vKff04obZl" Aug 29 15:47:35 volumio go-librespot[2401]: time="2024-08-29T15:47:35+07:00" level=debug msg="fetched first chunk of 23, total size is 11554808 bytes" uri="spotify:track:4rWdiOhPQVk4vKff04obZl" Aug 29 15:47:35 volumio go-librespot[2401]: time="2024-08-29T15:47:35+07:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:4rWdiOhPQVk4vKff04obZl" Aug 29 15:47:35 volumio go-librespot[2401]: time="2024-08-29T15:47:35+07:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 5102 us, period size = 225 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 98 frames" Aug 29 15:47:35 volumio go-librespot[2401]: time="2024-08-29T15:47:35+07:00" level=info msg="loaded track \"อาจเป็นเพราะฉันเอง (me.)\" (paused: false, position: 0ms, duration: 283079ms, prefetched: false)" uri="spotify:track:4rWdiOhPQVk4vKff04obZl" Aug 29 15:47:35 volumio go-librespot[2401]: time="2024-08-29T15:47:35+07:00" level=debug msg="fetched chunk 1/22, size: 524288" uri="spotify:track:4rWdiOhPQVk4vKff04obZl" Aug 29 15:47:35 volumio go-librespot[2401]: time="2024-08-29T15:47:35+07:00" level=debug msg="fetched chunk 2/22, size: 524288" uri="spotify:track:4rWdiOhPQVk4vKff04obZl" Aug 29 15:47:35 volumio go-librespot[2401]: time="2024-08-29T15:47:35+07:00" level=debug msg="fetched chunk 3/22, size: 524288" uri="spotify:track:4rWdiOhPQVk4vKff04obZl" Aug 29 15:47:35 volumio go-librespot[2401]: time="2024-08-29T15:47:35+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:47:35 volumio go-librespot[2401]: time="2024-08-29T15:47:35+07:00" level=trace msg="scheduling prefetch in 253s" Aug 29 15:47:35 volumio go-librespot[2401]: time="2024-08-29T15:47:35+07:00" level=trace msg="emitting websocket event: metadata" Aug 29 15:47:35 volumio volumio[809]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4rWdiOhPQVk4vKff04obZl","name":"อาจเป็นเพราะฉันเอง (me.)","artist_names":["PURPEECH"],"album_name":"อาจเป็นเพราะฉันเอง (me.)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e021865ed9016a97b14005951e7","position":0,"duration":283079,"release_date":"year:2023 month:4 day:5","track_number":1,"disc_number":1}} Aug 29 15:47:35 volumio go-librespot[2401]: time="2024-08-29T15:47:35+07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 29 15:47:35 volumio go-librespot[2401]: time="2024-08-29T15:47:35+07:00" level=trace msg="emitting websocket event: playing" Aug 29 15:47:35 volumio volumio[809]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4rWdiOhPQVk4vKff04obZl","play_origin":"go-librespot"}} Aug 29 15:47:35 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Aug 29 15:47:35 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"อาจเป็นเพราะฉันเอง (me.)","artist":"PURPEECH","album":"อาจเป็นเพราะฉันเอง (me.)","albumart":"https://i.scdn.co/image/ab67616d00001e021865ed9016a97b14005951e7","uri":"spotify:track:4rWdiOhPQVk4vKff04obZl","trackType":"spotify","seek":0,"duration":283,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:47:35 volumio volumio[809]: info: CoreCommandRouter::servicePushState Aug 29 15:47:35 volumio volumio[809]: info: CorePlayQueue::getTrack 97 Aug 29 15:47:35 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"อาจเป็นเพราะฉันเอง (me.)","artist":"PURPEECH","album":"อาจเป็นเพราะฉันเอง (me.)","albumart":"https://i.scdn.co/image/ab67616d00001e021865ed9016a97b14005951e7","uri":"spotify:track:4rWdiOhPQVk4vKff04obZl","trackType":"spotify","seek":0,"duration":283,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:47:35 volumio volumio[809]: verbose: CURRENT POSITION 97 Aug 29 15:47:35 volumio volumio[809]: info: CoreStateMachine::syncState stateService play Aug 29 15:47:35 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus stop Aug 29 15:47:35 volumio volumio[809]: SPOTIFY: PUSH STATE SPOTIFY Aug 29 15:47:35 volumio volumio[809]: SPOTIFY: {"status":"play","service":"spop","title":"อาจเป็นเพราะฉันเอง (me.)","artist":"PURPEECH","album":"อาจเป็นเพราะฉันเอง (me.)","albumart":"https://i.scdn.co/image/ab67616d00001e021865ed9016a97b14005951e7","uri":"spotify:track:4rWdiOhPQVk4vKff04obZl","trackType":"spotify","seek":0,"duration":283,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:47:35 volumio volumio[809]: info: CoreCommandRouter::servicePushState Aug 29 15:47:35 volumio volumio[809]: info: CorePlayQueue::getTrack 97 Aug 29 15:47:35 volumio volumio[809]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"อาจเป็นเพราะฉันเอง (me.)","artist":"PURPEECH","album":"อาจเป็นเพราะฉันเอง (me.)","albumart":"https://i.scdn.co/image/ab67616d00001e021865ed9016a97b14005951e7","uri":"spotify:track:4rWdiOhPQVk4vKff04obZl","trackType":"spotify","seek":0,"duration":283,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 29 15:47:35 volumio volumio[809]: verbose: CURRENT POSITION 97 Aug 29 15:47:35 volumio volumio[809]: info: CoreStateMachine::syncState stateService play Aug 29 15:47:35 volumio volumio[809]: info: CoreStateMachine::syncState currentStatus play Aug 29 15:47:35 volumio volumio[809]: info: Received an update from plugin. extracting info from payload Aug 29 15:47:35 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:47:35 volumio volumio[809]: info: CorePlayQueue::getTrack 97 Aug 29 15:47:35 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 15:47:35 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:47:35 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:47:35 volumio volumio[809]: info: CorePlayQueue::getTrack 97 Aug 29 15:47:35 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:47:38 volumio volumio[809]: info: CoreCommandRouter::getUIConfigOnPlugin Aug 29 15:47:38 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 29 15:47:38 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 29 15:47:38 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Aug 29 15:47:39 volumio volumio[809]: info: Received Get System Version Aug 29 15:47:39 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 29 15:47:41 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Aug 29 15:47:41 volumio volumio[809]: info: CorePlayQueue::getTrack 97 Aug 29 15:47:42 volumio volumio[809]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Total Clients: 8 Aug 29 15:47:42 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Aug 29 15:47:42 volumio volumio[809]: info: CorePlayQueue::getTrack 97 Aug 29 15:47:42 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 29 15:47:42 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Aug 29 15:47:44 volumio go-librespot[2401]: time="2024-08-29T15:47:44+07:00" level=debug msg="fetched chunk 4/22, size: 524288" uri="spotify:track:4rWdiOhPQVk4vKff04obZl" Aug 29 15:47:45 volumio volumio[809]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Total Clients: 9 Aug 29 15:47:46 volumio volumio[809]: info: peppy_screensaver: Start PeppyMeter Aug 29 15:47:47 volumio go-librespot[2401]: time="2024-08-29T15:47:47+07:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Aug 29 15:47:47 volumio volumio[809]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify Aug 29 15:47:47 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 29 15:47:47 volumio volumio[809]: info: Disabling plugin spop Aug 29 15:47:47 volumio volumio[809]: info: Done. Aug 29 15:47:47 volumio sudo[2511]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service Aug 29 15:47:47 volumio sudo[2511]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 29 15:47:47 volumio volumio[809]: info: Connection to go-librespot Websocket closed Aug 29 15:47:47 volumio systemd[1]: Stopping go-librespot Daemon... Aug 29 15:47:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Aug 29 15:47:47 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Aug 29 15:47:47 volumio systemd[1]: Stopped go-librespot Daemon. Aug 29 15:47:47 volumio sudo[2511]: pam_unix(sudo:session): session closed for user root Aug 29 15:47:50 volumio volumio[809]: info: CoreCommandRouter::volumioGetState Aug 29 15:47:50 volumio volumio[809]: info: CorePlayQueue::getTrack 97 Aug 29 15:47:50 volumio volumio[809]: info: CoreCommandRouter::volumioNext Aug 29 15:47:50 volumio volumio[809]: info: CoreStateMachine::next Aug 29 15:47:50 volumio volumio[809]: info: CoreStateMachine::stop Aug 29 15:47:50 volumio volumio[809]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 29 15:47:50 volumio volumio[809]: info: CoreStateMachine::stPlaybackTimer Aug 29 15:47:50 volumio volumio[809]: info: CoreStateMachine::updateTrackBlock Aug 29 15:47:50 volumio volumio[809]: info: CorePlayQueue::getTrackBlock Aug 29 15:47:50 volumio volumio[809]: info: CoreStateMachine::pushState Aug 29 15:47:50 volumio volumio[809]: info: CorePlayQueue::getTrack 97 Aug 29 15:47:50 volumio volumio[809]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 29 15:47:50 volumio volumio[809]: info: CoreCommandRouter::volumioPushState Aug 29 15:47:50 volumio volumio[809]: info: CoreStateMachine::serviceStop Aug 29 15:47:50 volumio volumio[809]: info: CorePlayQueue::getTrack 97 Aug 29 15:47:50 volumio volumio[809]: info: CoreCommandRouter::serviceStop Aug 29 15:47:50 volumio volumio[809]: error: WARNING: No stop method for service spop Aug 29 15:47:50 volumio volumio[809]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 15:47:50 volumio volumio[809]: TypeError: Cannot read property 'then' of undefined Aug 29 15:47:50 volumio volumio[809]: at CoreStateMachine.next (/volumio/app/statemachine.js:1167:9) Aug 29 15:47:50 volumio volumio[809]: at CoreCommandRouter.volumioNext (/volumio/app/index.js:101:28) Aug 29 15:47:50 volumio volumio[809]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:250:26) Aug 29 15:47:50 volumio volumio[809]: at Socket.emit (events.js:315:20) Aug 29 15:47:50 volumio volumio[809]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Aug 29 15:47:50 volumio volumio[809]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Aug 29 15:47:50 volumio volumio[809]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 29 15:47:51 volumio sudo[2524]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-29 15:46 Aug 29 15:47:51 volumio sudo[2524]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"