Jan 10 16:41:06 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:06+05:00" level=trace msg="sent dealer ping" Jan 10 16:41:06 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 1 Jan 10 16:41:06 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:06 my-volumio-3 volumio[1239]: info: Prefetching next song Jan 10 16:41:06 my-volumio-3 volumio[1239]: info: [1768045266121] ControllerSpotify::prefetch Jan 10 16:41:06 my-volumio-3 volumio[1239]: info: Sending Spotify command with payload to local API: /player/add_to_queue Jan 10 16:41:06 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:06+05:00" level=trace msg="received dealer pong" Jan 10 16:41:06 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:06+05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 10 16:41:06 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:06+05:00" level=debug msg="prefetching next track" uri="spotify:track:0DIGEuLzTRIF9jtmKQlPW4" Jan 10 16:41:06 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:06+05:00" level=debug msg="selected format OGG_VORBIS_320 (ea56f6f6136aa242af3ad72934ff72647b595fd1)" uri="spotify:track:0DIGEuLzTRIF9jtmKQlPW4" Jan 10 16:41:06 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:06+05:00" level=debug msg="requested aes key for file ea56f6f6136aa242af3ad72934ff72647b595fd1, gid: 0DIGEuLzTRIF9jtmKQlPW4" Jan 10 16:41:07 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:07+05:00" level=trace msg="found 2 cdn urls" uri="spotify:track:0DIGEuLzTRIF9jtmKQlPW4" Jan 10 16:41:08 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:08+05:00" level=debug msg="fetched first chunk of 14, total size is 7151228 bytes" uri="spotify:track:0DIGEuLzTRIF9jtmKQlPW4" Jan 10 16:41:08 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:08+05:00" level=info msg="prefetched track \"Aap Ki Ankhon Mein Kuch (From \\\"Ghar\\\")\" (duration: 249173ms)" uri="spotify:track:0DIGEuLzTRIF9jtmKQlPW4" Jan 10 16:41:08 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:08+05:00" level=debug msg="fetched chunk 1/13, size: 524288" uri="spotify:track:0DIGEuLzTRIF9jtmKQlPW4" Jan 10 16:41:08 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:08+05:00" level=debug msg="fetched chunk 2/13, size: 524288" uri="spotify:track:0DIGEuLzTRIF9jtmKQlPW4" Jan 10 16:41:08 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:08+05:00" level=debug msg="fetched chunk 3/13, size: 524288" uri="spotify:track:0DIGEuLzTRIF9jtmKQlPW4" Jan 10 16:41:10 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:10+05:00" level=trace msg="emitting websocket event: not_playing" Jan 10 16:41:10 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:10+05:00" level=debug msg="loading track (paused: false, position: 1ms)" uri="spotify:track:0DIGEuLzTRIF9jtmKQlPW4" Jan 10 16:41:10 my-volumio-3 volumio[1239]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:track:1o9XGfmelBzG1mlTRs1OLI","uri":"spotify:track:1nmlPoLiWFUeWd1sN2myIV","play_origin":"go-librespot"}} Jan 10 16:41:10 my-volumio-3 volumio[1239]: error: Failed to decode event: not_playing Jan 10 16:41:10 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:10+05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 10 16:41:10 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:10+05:00" level=trace msg="emitting websocket event: will_play" Jan 10 16:41:10 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:10+05:00" level=info msg="loaded track \"Aap Ki Ankhon Mein Kuch (From \\\"Ghar\\\")\" (paused: false, position: 1ms, duration: 249173ms, prefetched: true)" uri="spotify:track:0DIGEuLzTRIF9jtmKQlPW4" Jan 10 16:41:10 my-volumio-3 volumio[1239]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:track:1o9XGfmelBzG1mlTRs1OLI","uri":"spotify:track:0DIGEuLzTRIF9jtmKQlPW4","play_origin":"go-librespot"}} Jan 10 16:41:10 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:10+05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 10 16:41:10 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:10+05:00" level=trace msg="scheduling prefetch in 219s" Jan 10 16:41:10 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:10+05:00" level=trace msg="emitting websocket event: metadata" Jan 10 16:41:10 my-volumio-3 volumio[1239]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0DIGEuLzTRIF9jtmKQlPW4","name":"Aap Ki Ankhon Mein Kuch (From \"Ghar\")","artist_names":["Kishore Kumar","Lata Mangeshkar"],"album_name":"Krazy Kishore","album_cover_url":"https://i.scdn.co/image/ab67616d00001e026f116e3aba2e893cb09f6068","position":1,"duration":249173,"release_date":"year:2018 month:4 day:24","track_number":3,"disc_number":1}} Jan 10 16:41:10 my-volumio-3 volumio[1239]: info: CoreStateMachine::startPlaybackTimer Jan 10 16:41:10 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:10 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:10+05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 10 16:41:10 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:10+05:00" level=trace msg="emitting websocket event: playing" Jan 10 16:41:10 my-volumio-3 volumio[1239]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:1o9XGfmelBzG1mlTRs1OLI","uri":"spotify:track:0DIGEuLzTRIF9jtmKQlPW4","resume":false,"play_origin":"go-librespot"}} Jan 10 16:41:10 my-volumio-3 volumio[1239]: SPOTIFY: PUSH STATE SPOTIFY Jan 10 16:41:10 my-volumio-3 volumio[1239]: SPOTIFY: {"status":"play","service":"spop","title":"Aap Ki Ankhon Mein Kuch (From \"Ghar\")","artist":"Kishore Kumar, Lata Mangeshkar","album":"Krazy Kishore","albumart":"https://i.scdn.co/image/ab67616d00001e026f116e3aba2e893cb09f6068","uri":"spotify:track:0DIGEuLzTRIF9jtmKQlPW4","trackType":"spotify","seek":1,"duration":249,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 10 16:41:10 my-volumio-3 volumio[1239]: info: CoreCommandRouter::servicePushState Jan 10 16:41:10 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:10 my-volumio-3 volumio[1239]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Aap Ki Ankhon Mein Kuch (From \"Ghar\")","artist":"Kishore Kumar, Lata Mangeshkar","album":"Krazy Kishore","albumart":"https://i.scdn.co/image/ab67616d00001e026f116e3aba2e893cb09f6068","uri":"spotify:track:0DIGEuLzTRIF9jtmKQlPW4","trackType":"spotify","seek":1,"duration":249,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 10 16:41:10 my-volumio-3 volumio[1239]: verbose: CURRENT POSITION 2 Jan 10 16:41:10 my-volumio-3 volumio[1239]: info: CoreStateMachine::syncState stateService play Jan 10 16:41:10 my-volumio-3 volumio[1239]: info: CoreStateMachine::syncState currentStatus play Jan 10 16:41:10 my-volumio-3 volumio[1239]: info: Received an update from plugin. extracting info from payload Jan 10 16:41:10 my-volumio-3 volumio[1239]: info: CoreStateMachine::pushState Jan 10 16:41:10 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:10 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 16:41:10 my-volumio-3 volumio[1239]: info: CoreCommandRouter::volumioPushState Jan 10 16:41:10 my-volumio-3 volumio[1239]: info: CoreStateMachine::pushState Jan 10 16:41:10 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:10 my-volumio-3 volumio[1239]: info: CoreCommandRouter::volumioPushState Jan 10 16:41:10 my-volumio-3 volumio[1239]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jan 10 16:41:10 my-volumio-3 volumio[1239]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jan 10 16:41:11 my-volumio-3 volumio[1239]: info: CoreStateMachine::pushState Jan 10 16:41:11 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:11 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 16:41:11 my-volumio-3 volumio[1239]: info: CoreCommandRouter::volumioPushState Jan 10 16:41:11 my-volumio-3 volumio[1239]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jan 10 16:41:11 my-volumio-3 volumio[1239]: SPOTIFY: PUSH STATE SPOTIFY Jan 10 16:41:11 my-volumio-3 volumio[1239]: SPOTIFY: {"status":"play","service":"spop","title":"Aap Ki Ankhon Mein Kuch (From \"Ghar\")","artist":"Kishore Kumar, Lata Mangeshkar","album":"Krazy Kishore","albumart":"https://i.scdn.co/image/ab67616d00001e026f116e3aba2e893cb09f6068","uri":"spotify:track:0DIGEuLzTRIF9jtmKQlPW4","trackType":"spotify","seek":1,"duration":249,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 10 16:41:11 my-volumio-3 volumio[1239]: info: CoreCommandRouter::servicePushState Jan 10 16:41:11 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:11 my-volumio-3 volumio[1239]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Aap Ki Ankhon Mein Kuch (From \"Ghar\")","artist":"Kishore Kumar, Lata Mangeshkar","album":"Krazy Kishore","albumart":"https://i.scdn.co/image/ab67616d00001e026f116e3aba2e893cb09f6068","uri":"spotify:track:0DIGEuLzTRIF9jtmKQlPW4","trackType":"spotify","seek":1,"duration":249,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 10 16:41:11 my-volumio-3 volumio[1239]: verbose: CURRENT POSITION 2 Jan 10 16:41:11 my-volumio-3 volumio[1239]: info: CoreStateMachine::syncState stateService play Jan 10 16:41:11 my-volumio-3 volumio[1239]: info: CoreStateMachine::syncState currentStatus play Jan 10 16:41:11 my-volumio-3 volumio[1239]: info: Received an update from plugin. extracting info from payload Jan 10 16:41:11 my-volumio-3 volumio[1239]: info: CoreStateMachine::pushState Jan 10 16:41:11 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:11 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 16:41:11 my-volumio-3 volumio[1239]: info: CoreCommandRouter::volumioPushState Jan 10 16:41:11 my-volumio-3 volumio[1239]: info: CoreStateMachine::pushState Jan 10 16:41:11 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:11 my-volumio-3 volumio[1239]: info: CoreCommandRouter::volumioPushState Jan 10 16:41:11 my-volumio-3 volumio[1239]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jan 10 16:41:11 my-volumio-3 volumio[1239]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jan 10 16:41:28 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:28+05:00" level=debug msg="fetched chunk 4/13, size: 524288" uri="spotify:track:0DIGEuLzTRIF9jtmKQlPW4" Jan 10 16:41:36 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:36+05:00" level=trace msg="sent dealer ping" Jan 10 16:41:36 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:36+05:00" level=trace msg="received dealer pong" Jan 10 16:41:46 my-volumio-3 volumio[1239]: verbose: New Socket.io Connection to 192.168.11.181:3000 from 192.168.11.245 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: Discovery: Getting this device information Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::volumioGetState Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 16:41:46 my-volumio-3 volumio[1239]: verbose: New Socket.io Connection to 192.168.11.181:3000 from 192.168.11.245 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6 Jan 10 16:41:46 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:46+05:00" level=debug msg="fetched chunk 5/13, size: 524288" uri="spotify:track:0DIGEuLzTRIF9jtmKQlPW4" Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: Discovery: Getting this device information Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::volumioGetState Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: Discovery: Getting this device information Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::volumioGetState Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: Discovery: Getting this device information Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::volumioGetState Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 10 16:41:46 my-volumio-3 volumio[1239]: verbose: New Socket.io Connection to 192.168.11.181:3000 from 192.168.11.245 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Jan 10 16:41:46 my-volumio-3 sudo[4796]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Jan 10 16:41:46 my-volumio-3 sudo[4796]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 16:41:46 my-volumio-3 sudo[4801]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 10 16:41:46 my-volumio-3 sudo[4801]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 16:41:46 my-volumio-3 sudo[4796]: pam_unix(sudo:session): session closed for user root Jan 10 16:41:46 my-volumio-3 sudo[4807]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 10 16:41:46 my-volumio-3 sudo[4807]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 16:41:46 my-volumio-3 sudo[4801]: pam_unix(sudo:session): session closed for user root Jan 10 16:41:46 my-volumio-3 sudo[4807]: pam_unix(sudo:session): session closed for user root Jan 10 16:41:46 my-volumio-3 sudo[4812]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Jan 10 16:41:46 my-volumio-3 sudo[4812]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 16:41:46 my-volumio-3 sudo[4819]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 10 16:41:46 my-volumio-3 sudo[4819]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 16:41:46 my-volumio-3 sudo[4812]: pam_unix(sudo:session): session closed for user root Jan 10 16:41:46 my-volumio-3 sudo[4819]: pam_unix(sudo:session): session closed for user root Jan 10 16:41:46 my-volumio-3 sudo[4824]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 10 16:41:46 my-volumio-3 sudo[4824]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 16:41:46 my-volumio-3 sudo[4824]: pam_unix(sudo:session): session closed for user root Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: Discovery: Getting this device information Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::volumioGetState Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: Discovery: Getting this device information Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::volumioGetState Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::volumioGetState Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:46 my-volumio-3 volumio[1239]: verbose: New Socket.io Connection to 192.168.11.181:3000 from 192.168.11.245 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 10 16:41:46 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 10 16:41:56 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 16:41:56 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 16:41:56 my-volumio-3 volumio[1239]: info: Discovery: Getting this device information Jan 10 16:41:56 my-volumio-3 volumio[1239]: info: CoreCommandRouter::volumioGetState Jan 10 16:41:56 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:56 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 16:41:56 my-volumio-3 volumio[1239]: verbose: New Socket.io Connection to 192.168.11.181:3000 from 192.168.11.245 UA: Dart/3.10 (dart:io) Engine version: 3 Transport: websocket Total Clients: 7 Jan 10 16:41:56 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Jan 10 16:41:56 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:58+05:00" level=info msg="playback was transferred to My Volumio Digi" Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:58+05:00" level=trace msg="closed output device because of stop command" Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:58+05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 411" Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:58+05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1138" Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:58+05:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:58+05:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:58+05:00" level=debug msg="put connect state inactive" Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:58+05:00" level=trace msg="emitting websocket event: inactive" Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:58+05:00" level=trace msg="emitting websocket event: stopped" Jan 10 16:41:58 my-volumio-3 volumio[1239]: SPOTIFY: received: {"type":"inactive","data":null} Jan 10 16:41:58 my-volumio-3 volumio[1239]: error: Failed to decode event: inactive Jan 10 16:41:58 my-volumio-3 volumio[1239]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":""}} Jan 10 16:41:58 my-volumio-3 volumio[1239]: SPOTIFY: PUSH STATE SPOTIFY Jan 10 16:41:58 my-volumio-3 volumio[1239]: SPOTIFY: {"status":"stop","service":"spop","title":"Aap Ki Ankhon Mein Kuch (From \"Ghar\")","artist":"Kishore Kumar, Lata Mangeshkar","album":"Krazy Kishore","albumart":"https://i.scdn.co/image/ab67616d00001e026f116e3aba2e893cb09f6068","uri":"spotify:track:0DIGEuLzTRIF9jtmKQlPW4","trackType":"spotify","seek":48001,"duration":249,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CoreCommandRouter::servicePushState Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CoreStateMachine::pushState Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CoreCommandRouter::volumioPushState Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 2 Jan 10 16:41:58 my-volumio-3 volumio[1239]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"Aap Ki Ankhon Mein Kuch (From \"Ghar\")","artist":"Kishore Kumar, Lata Mangeshkar","album":"Krazy Kishore","albumart":"https://i.scdn.co/image/ab67616d00001e026f116e3aba2e893cb09f6068","uri":"spotify:track:0DIGEuLzTRIF9jtmKQlPW4","trackType":"spotify","seek":48001,"duration":249,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Jan 10 16:41:58 my-volumio-3 volumio[1239]: verbose: CURRENT POSITION 2 Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CoreStateMachine::syncState stateService stop Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CoreStateMachine::syncState currentStatus play Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CoreStateMachine::play index undefined Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CoreStateMachine::pushState Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 3 Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CoreCommandRouter::volumioPushState Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 3 Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CoreStateMachine::startPlaybackTimer Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 3 Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: [1768045318803] ControllerSpotify::clearAddPlayTrack Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: Sending Spotify command with payload to local API: /player/play Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CoreStateMachine::pushState Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CorePlayQueue::getTrack 3 Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: CoreCommandRouter::volumioPushState Jan 10 16:41:58 my-volumio-3 volumio[1239]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jan 10 16:41:58 my-volumio-3 volumio[1239]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jan 10 16:41:58 my-volumio-3 volumio[1239]: SPOTIFY: RECEIVED VOLUMIO VOLUME 77 Jan 10 16:41:58 my-volumio-3 systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:58+05:00" level=debug msg="dealer connection closed" Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: time="2026-01-10T16:41:58+05:00" level=debug msg="dealer recv loop stopped" Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: panic: send on closed channel Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 27 gp=0x2318a28 m=9 mp=0x204a108 [running]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: panic({0x6cfbf0, 0x881b80}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/panic.go:779 +0x12c fp=0x2295f48 sp=0x2295ef4 pc=0x58bf8 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.chansend(0x20903c0, 0x2295fa8, 0x1, 0x63e7c8) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/chan.go:283 +0x5e4 fp=0x2295f80 sp=0x2295f48 pc=0x1f474 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.chansend1(0x20903c0, 0x2295fa8) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/chan.go:145 +0x28 fp=0x2295f98 sp=0x2295f80 pc=0x1ee8c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: main.(*App).withAppPlayer.func1() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/cmd/daemon/main.go:275 +0x9c fp=0x2295fec sp=0x2295f98 pc=0x63e7c8 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2295fec sp=0x2295fec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by main.(*App).withAppPlayer in goroutine 1 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/cmd/daemon/main.go:265 +0x464 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 1 gp=0x2002128 m=nil [select, 21 minutes]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e4134, 0x0, 0x9, 0x3, 0x1) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2056d00 sp=0x2056cec pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.selectgo(0x2056e00, 0x2263dcc, 0x0, 0x0, 0x2, 0x1) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/select.go:327 +0xaf0 fp=0x2056da0 sp=0x2056d00 pc=0x70e78 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve(0x23500c0, 0x2056e90) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/zeroconf/zeroconf.go:283 +0x228 fp=0x2056e44 sp=0x2056da0 pc=0x5a8088 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: main.(*App).withAppPlayer(0x2176300, {0x8874f0, 0xd0ad00}, 0x2117090) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/cmd/daemon/main.go:321 +0x554 fp=0x2056ed0 sp=0x2056e44 pc=0x63db54 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: main.(*App).withCredentials(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/cmd/daemon/main.go:193 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: main.(*App).SpotifyToken(0x2176300, {0x8874f0, 0xd0ad00}, {0x212c680, 0x1c}, {0x2286000, 0x13c}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/cmd/daemon/main.go:185 +0xd8 fp=0x2056f00 sp=0x2056ed0 pc=0x63cfa8 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: main.main() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/cmd/daemon/main.go:557 +0x588 fp=0x2056fa8 sp=0x2056f00 pc=0x63feb4 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.main() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:271 +0x2fc fp=0x2056fec sp=0x2056fa8 pc=0x5cb30 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2056fec sp=0x2056fec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 2 gp=0x2002c68 m=nil [force gc (idle), 21 minutes]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e4100, 0xcdf428, 0x11, 0xa, 0x1) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2044fd4 sp=0x2044fc0 pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goparkunlock(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:408 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.forcegchelper() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:326 +0xe4 fp=0x2044fec sp=0x2044fd4 pc=0x5cefc Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2044fec sp=0x2044fec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by runtime.init.5 in goroutine 1 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:314 +0x1c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 3 gp=0x2002d88 m=nil [GC sweep wait]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e4100, 0xcdfbe0, 0xc, 0x9, 0x1) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x20457c4 sp=0x20457b0 pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goparkunlock(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:408 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.bgsweep(0x2074000) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mgcsweep.go:318 +0x11c fp=0x20457e4 sp=0x20457c4 pc=0x45848 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gcenable.gowrap1() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mgc.go:203 +0x28 fp=0x20457ec sp=0x20457e4 pc=0x35968 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x20457ec sp=0x20457ec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by runtime.gcenable in goroutine 1 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mgc.go:203 +0x74 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 4 gp=0x2002ea8 m=nil [GC scavenge wait]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e4100, 0xce0208, 0xd, 0xa, 0x2) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2045fb4 sp=0x2045fa0 pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goparkunlock(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:408 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.(*scavengerState).park(0xce0208) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mgcscavenge.go:425 +0x68 fp=0x2045fc8 sp=0x2045fb4 pc=0x42b68 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.bgscavenge(0x2074000) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mgcscavenge.go:658 +0x60 fp=0x2045fe4 sp=0x2045fc8 pc=0x432a0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gcenable.gowrap2() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mgc.go:204 +0x28 fp=0x2045fec sp=0x2045fe4 pc=0x35914 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2045fec sp=0x2045fec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by runtime.gcenable in goroutine 1 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mgc.go:204 +0xbc Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 18 gp=0x2084488 m=nil [finalizer wait]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e3fac, 0xd0ad9c, 0x10, 0xa, 0x1) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x204078c sp=0x2040778 pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.runfinq() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mfinal.go:194 +0x110 fp=0x20407ec sp=0x204078c pc=0x34754 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x20407ec sp=0x20407ec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by runtime.createfing in goroutine 1 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mfinal.go:164 +0x5c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 36 gp=0x2132fc8 m=nil [IO wait]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e40f0, 0x74f82f08, 0x2, 0x2, 0x5) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x22dad28 sp=0x22dad14 pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.netpollblock(0x74f82ef8, 0x72, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/netpoll.go:573 +0x100 fp=0x22dad40 sp=0x22dad28 pc=0x548cc Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.runtime_pollWait(0x74f82ef8, 0x72) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/netpoll.go:345 +0x54 fp=0x22dad54 sp=0x22dad40 pc=0x8f4a8 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*pollDesc).wait(0x21270f8, 0x72, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x22dad68 sp=0x22dad54 pc=0x10a318 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*pollDesc).waitRead(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*FD).Accept(0x21270e0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_unix.go:611 +0x294 fp=0x22dadb0 sp=0x22dad68 pc=0x10eb84 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net.(*netFD).accept(0x21270e0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/fd_unix.go:172 +0x20 fp=0x22dae18 sp=0x22dadb0 pc=0x17e4c4 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net.(*TCPListener).accept(0x21225e8) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/tcpsock_posix.go:159 +0x20 fp=0x22dae30 sp=0x22dae18 pc=0x196900 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net.(*TCPListener).Accept(0x21225e8) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/tcpsock.go:327 +0x30 fp=0x22dae4c sp=0x22dae30 pc=0x19596c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.(*onceCloseListener).Accept(0x20a96c0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: :1 +0x34 fp=0x22dae64 sp=0x22dae4c pc=0x362b54 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.(*Server).Serve(0x20a7cc8, {0x886cb8, 0x21225e8}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:3255 +0x314 fp=0x22daefc sp=0x22dae64 pc=0x341210 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.Serve(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:2794 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: main.(*ConcreteApiServer).serve(0x211c300) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/cmd/daemon/api_server.go:630 +0x974 fp=0x22dafe4 sp=0x22daefc pc=0x6330b8 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: main.NewApiServer.gowrap1() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/cmd/daemon/api_server.go:296 +0x28 fp=0x22dafec sp=0x22dafe4 pc=0x631de4 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x22dafec sp=0x22dafec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by main.NewApiServer in goroutine 1 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/cmd/daemon/api_server.go:296 +0x310 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 37 gp=0x21330e8 m=nil [GC worker (idle)]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e3fbc, 0x21742a0, 0x1a, 0xa, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2298790 sp=0x229877c pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gcBgMarkWorker() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mgc.go:1310 +0xec fp=0x22987ec sp=0x2298790 pc=0x38590 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x22987ec sp=0x22987ec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by runtime.gcBgMarkStartWorkers in goroutine 50 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mgc.go:1234 +0x20 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 52 gp=0x2318248 m=nil [GC worker (idle)]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e3fbc, 0x20a2b28, 0x1a, 0xa, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2294790 sp=0x229477c pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gcBgMarkWorker() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mgc.go:1310 +0xec fp=0x22947ec sp=0x2294790 pc=0x38590 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x22947ec sp=0x22947ec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by runtime.gcBgMarkStartWorkers in goroutine 50 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mgc.go:1234 +0x20 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 38 gp=0x2133208 m=nil [GC worker (idle)]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e3fbc, 0x20a2b40, 0x1a, 0xa, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2299790 sp=0x229977c pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gcBgMarkWorker() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mgc.go:1310 +0xec fp=0x22997ec sp=0x2299790 pc=0x38590 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x22997ec sp=0x22997ec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by runtime.gcBgMarkStartWorkers in goroutine 50 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mgc.go:1234 +0x20 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 19 gp=0x2084c68 m=nil [GC worker (idle)]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e3fbc, 0x21742b8, 0x1a, 0xa, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2040f90 sp=0x2040f7c pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gcBgMarkWorker() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mgc.go:1310 +0xec fp=0x2040fec sp=0x2040f90 pc=0x38590 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2040fec sp=0x2040fec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by runtime.gcBgMarkStartWorkers in goroutine 50 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/mgc.go:1234 +0x20 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 39 gp=0x2132008 m=nil [IO wait]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e40f0, 0x74f82d28, 0x2, 0x2, 0x5) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x22dfe84 sp=0x22dfe70 pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.netpollblock(0x74f82d18, 0x72, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/netpoll.go:573 +0x100 fp=0x22dfe9c sp=0x22dfe84 pc=0x548cc Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.runtime_pollWait(0x74f82d18, 0x72) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/netpoll.go:345 +0x54 fp=0x22dfeb0 sp=0x22dfe9c pc=0x8f4a8 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*pollDesc).wait(0x21269c8, 0x72, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x22dfec4 sp=0x22dfeb0 pc=0x10a318 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*pollDesc).waitRead(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*FD).RawRead(0x21269b0, 0x20000f0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_unix.go:708 +0x164 fp=0x22dfef0 sp=0x22dfec4 pc=0x10f788 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net.(*rawConn).Read(0x2100198, 0x20000f0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/rawconn.go:44 +0x38 fp=0x22dff10 sp=0x22dfef0 pc=0x190d28 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: golang.org/x/net/internal/socket.(*Conn).recvMsg(0x2116bd0, 0x20000c0, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/golang.org/x/net@v0.26.0/internal/socket/rawconn_msg.go:27 +0x154 fp=0x22dff40 sp=0x22dff10 pc=0x548824 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: golang.org/x/net/internal/socket.(*Conn).RecvMsg(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/golang.org/x/net@v0.26.0/internal/socket/socket.go:247 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: golang.org/x/net/ipv4.(*payloadHandler).ReadFrom(0x21616b8, {0x2500000, 0x10000, 0x10000}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/golang.org/x/net@v0.26.0/ipv4/payload_cmsg.go:31 +0x44c fp=0x22dff9c sp=0x22dff40 pc=0x54c80c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: github.com/grandcat/zeroconf.(*Server).recv4(0x2118c80, 0x21616b0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:254 +0xec fp=0x22dffe0 sp=0x22dff9c pc=0x5a309c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: github.com/grandcat/zeroconf.(*Server).mainloop.gowrap1() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:188 +0x30 fp=0x22dffec sp=0x22dffe0 pc=0x5a2d54 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x22dffec sp=0x22dffec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by github.com/grandcat/zeroconf.(*Server).mainloop in goroutine 10 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:188 +0x7c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 40 gp=0x2132128 m=nil [IO wait, 21 minutes]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e40f0, 0x74f82c88, 0x2, 0x2, 0x5) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x22e765c sp=0x22e7648 pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.netpollblock(0x74f82c78, 0x72, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/netpoll.go:573 +0x100 fp=0x22e7674 sp=0x22e765c pc=0x548cc Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.runtime_pollWait(0x74f82c78, 0x72) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/netpoll.go:345 +0x54 fp=0x22e7688 sp=0x22e7674 pc=0x8f4a8 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*pollDesc).wait(0x2126a18, 0x72, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x22e769c sp=0x22e7688 pc=0x10a318 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*pollDesc).waitRead(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*FD).RawRead(0x2126a00, 0x2001350) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_unix.go:708 +0x164 fp=0x22e76c8 sp=0x22e769c pc=0x10f788 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net.(*rawConn).Read(0x21001c0, 0x2001350) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/rawconn.go:44 +0x38 fp=0x22e76e8 sp=0x22e76c8 pc=0x190d28 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: golang.org/x/net/internal/socket.(*Conn).recvMsg(0x2116be0, 0x2001320, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/golang.org/x/net@v0.26.0/internal/socket/rawconn_msg.go:27 +0x154 fp=0x22e7718 sp=0x22e76e8 pc=0x548824 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: golang.org/x/net/internal/socket.(*Conn).RecvMsg(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/golang.org/x/net@v0.26.0/internal/socket/socket.go:247 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: golang.org/x/net/ipv6.(*payloadHandler).ReadFrom(0x21616e8, {0x22e8000, 0x10000, 0x10000}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/golang.org/x/net@v0.26.0/ipv6/payload_cmsg.go:31 +0x2ec fp=0x22e779c sp=0x22e7718 pc=0x550194 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: github.com/grandcat/zeroconf.(*Server).recv6(0x2118c80, 0x21616e0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:282 +0xec fp=0x22e77e0 sp=0x22e779c pc=0x5a3290 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: github.com/grandcat/zeroconf.(*Server).mainloop.gowrap2() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:191 +0x30 fp=0x22e77ec sp=0x22e77e0 pc=0x5a2cf8 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x22e77ec sp=0x22e77ec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by github.com/grandcat/zeroconf.(*Server).mainloop in goroutine 10 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:191 +0xe8 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 28 gp=0x2318b48 m=nil [runnable]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.asyncPreempt2() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/preempt.go:307 +0x38 fp=0x22dcbb4 sp=0x22dcba8 pc=0x5b450 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.asyncPreempt() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/preempt_arm.s:44 +0x98 fp=0x22dcc70 sp=0x22dcbb4 pc=0x948c4 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: fmt.Sprintf({0x791ee2, 0x6}, {0x22dccc0, 0x2, 0x2}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/fmt/print.go:238 +0x14 fp=0x22dcc9c sp=0x22dcc74 pc=0x121050 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: github.com/devgianlu/go-librespot.SpotifyLikeClientVersion() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/version.go:41 +0x18c fp=0x22dccd4 sp=0x22dcc9c pc=0x460178 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: github.com/devgianlu/go-librespot/session.retrieveClientToken(0x2106900, {0x21042a0, 0x28}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/session/client_token.go:22 +0x44 fp=0x22dcd6c sp=0x22dccd4 pc=0x5445c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: github.com/devgianlu/go-librespot/session.NewSessionFromOptions({0x8874f0, 0xd0ad00}, 0x22dcf18) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/session/session.go:70 +0x228 fp=0x22dced8 sp=0x22dcd6c pc=0x545aa8 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: main.(*App).newAppPlayer(0x2176300, {0x8874f0, 0xd0ad00}, {0x6daf48, 0x209e0a8}) Jan 10 16:41:58 my-volumio-3 volumio[1239]: info: Connection to go-librespot Websocket closed Jan 10 16:41:58 my-volumio-3 volumio[1239]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Jan 10 16:41:58 my-volumio-3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/cmd/daemon/main.go:121 +0x204 fp=0x22dcf50 sp=0x22dced8 pc=0x63cb28 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: main.(*App).SpotifyToken.(*App).withCredentials.func1({0x8874f0, 0xd0ad00}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/cmd/daemon/main.go:195 +0x26c fp=0x22dcf90 sp=0x22dcf50 pc=0x63d248 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: main.(*App).withAppPlayer.func2() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/cmd/daemon/main.go:298 +0x14c fp=0x22dcfec sp=0x22dcf90 pc=0x63e410 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x22dcfec sp=0x22dcfec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by main.(*App).withAppPlayer in goroutine 1 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/cmd/daemon/main.go:281 +0x504 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 29 gp=0x2318c68 m=nil [IO wait]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e40f0, 0x74f82dc8, 0x2, 0x2, 0x5) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2296de8 sp=0x2296dd4 pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.netpollblock(0x74f82db8, 0x72, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/netpoll.go:573 +0x100 fp=0x2296e00 sp=0x2296de8 pc=0x548cc Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.runtime_pollWait(0x74f82db8, 0x72) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/netpoll.go:345 +0x54 fp=0x2296e14 sp=0x2296e00 pc=0x8f4a8 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*pollDesc).wait(0x2126978, 0x72, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2296e28 sp=0x2296e14 pc=0x10a318 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*pollDesc).waitRead(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*FD).Accept(0x2126960) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_unix.go:611 +0x294 fp=0x2296e70 sp=0x2296e28 pc=0x10eb84 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net.(*netFD).accept(0x2126960) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/fd_unix.go:172 +0x20 fp=0x2296ed8 sp=0x2296e70 pc=0x17e4c4 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net.(*TCPListener).accept(0x247d068) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/tcpsock_posix.go:159 +0x20 fp=0x2296ef0 sp=0x2296ed8 pc=0x196900 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net.(*TCPListener).Accept(0x247d068) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/tcpsock.go:327 +0x30 fp=0x2296f0c sp=0x2296ef0 pc=0x19596c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.(*onceCloseListener).Accept(0x2106440) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: :1 +0x34 fp=0x2296f24 sp=0x2296f0c pc=0x362b54 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.(*Server).Serve(0x2354328, {0x886cb8, 0x247d068}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:3255 +0x314 fp=0x2296fbc sp=0x2296f24 pc=0x341210 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.Serve(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:2794 Jan 10 16:41:58 my-volumio-3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve.func2() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/zeroconf/zeroconf.go:280 +0x8c fp=0x2296fec sp=0x2296fbc pc=0x5a8184 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2296fec sp=0x2296fec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by github.com/devgianlu/go-librespot/zeroconf.(*Zeroconf).Serve in goroutine 1 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/zeroconf/zeroconf.go:280 +0x160 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 89 gp=0x2269328 m=nil [IO wait, 21 minutes]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e40f0, 0x74f828c8, 0x2, 0x2, 0x5) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x205587c sp=0x2055868 pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.netpollblock(0x74f828b8, 0x72, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/netpoll.go:573 +0x100 fp=0x2055894 sp=0x205587c pc=0x548cc Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.runtime_pollWait(0x74f828b8, 0x72) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/netpoll.go:345 +0x54 fp=0x20558a8 sp=0x2055894 pc=0x8f4a8 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*pollDesc).wait(0x229c5b8, 0x72, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x20558bc sp=0x20558a8 pc=0x10a318 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*pollDesc).waitRead(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*FD).Read(0x229c5a0, {0x22d0000, 0x1000, 0x1000}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_unix.go:164 +0x238 fp=0x2055904 sp=0x20558bc pc=0x10b504 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net.(*netFD).Read(0x229c5a0, {0x22d0000, 0x1000, 0x1000}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/fd_posix.go:55 +0x38 fp=0x2055930 sp=0x2055904 pc=0x17c5d0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net.(*conn).Read(0x23e51b0, {0x22d0000, 0x1000, 0x1000}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/net.go:179 +0x48 fp=0x205595c sp=0x2055930 pc=0x18caec Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net.(*TCPConn).Read(0x23e51b0, {0x22d0000, 0x1000, 0x1000}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: :1 +0x44 fp=0x205597c sp=0x205595c pc=0x19fd40 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: io.(*multiReader).Read(0x2117650, {0x22d0000, 0x1000, 0x1000}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/io/multi.go:26 +0xb4 fp=0x20559a8 sp=0x205597c pc=0x105528 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: bufio.(*Reader).fill(0x228f5c0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/bufio/bufio.go:110 +0x10c fp=0x20559cc sp=0x20559a8 pc=0x2bddb4 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: bufio.(*Reader).ReadByte(0x228f5c0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/bufio/bufio.go:269 +0x28 fp=0x20559d8 sp=0x20559cc pc=0x2be638 Jan 10 16:41:58 my-volumio-3 systemd[1]: go-librespot-daemon.service: Consumed 1min 9.575s CPU time. Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: nhooyr.io/websocket.readFrameHeader(0x228f5c0, {0x25982b8, 0x8, 0x8}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/frame.go:54 +0x74 fp=0x2055a18 sp=0x20559d8 pc=0x47788c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: nhooyr.io/websocket.(*Conn).readFrameHeader(0x2598288, {0x8874d0, 0xd0ad00}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/read.go:188 +0xb4 fp=0x2055ad8 sp=0x2055a18 pc=0x47a4f0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: nhooyr.io/websocket.(*Conn).readLoop(0x2598288, {0x8874d0, 0xd0ad00}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/read.go:146 +0x3c fp=0x2055b9c sp=0x2055ad8 pc=0x479fd8 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: nhooyr.io/websocket.(*Conn).reader(0x2598288, {0x8874d0, 0xd0ad00}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/read.go:315 +0x108 fp=0x2055c28 sp=0x2055b9c pc=0x47b1ec Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: nhooyr.io/websocket.(*Conn).Reader(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/read.go:30 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: nhooyr.io/websocket.(*Conn).Read(0x2598288, {0x8874d0, 0xd0ad00}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/read.go:36 +0x30 fp=0x2055c50 sp=0x2055c28 pc=0x4798bc Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: main.(*ConcreteApiServer).serve.func17({0x886dec, 0x2129688}, 0x2355688) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/cmd/daemon/api_server.go:600 +0x3c0 fp=0x2055ccc sp=0x2055c50 pc=0x633988 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.HandlerFunc.ServeHTTP(0x209a398, {0x886dec, 0x2129688}, 0x2355688) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:2166 +0x34 fp=0x2055cdc sp=0x2055ccc pc=0x33d7f4 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.(*ServeMux).ServeHTTP(0x20b4880, {0x886dec, 0x2129688}, 0x2355688) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:2683 +0x208 fp=0x2055d18 sp=0x2055cdc pc=0x33f654 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: main.(*ConcreteApiServer).serve.(*Cors).Handler.func19({0x886dec, 0x2129688}, 0x2355688) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/github.com/rs/cors@v1.11.1/cors.go:289 +0x1f8 fp=0x2055d40 sp=0x2055d18 pc=0x633388 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.HandlerFunc.ServeHTTP(0x20be590, {0x886dec, 0x2129688}, 0x2355688) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:2166 +0x34 fp=0x2055d50 sp=0x2055d40 pc=0x33d7f4 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.serverHandler.ServeHTTP({0x20a7cc8}, {0x886dec, 0x2129688}, 0x2355688) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:3137 +0xe0 fp=0x2055d6c sp=0x2055d50 pc=0x340de4 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.(*conn).serve(0x211d800, {0x887510, 0x209e3a8}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:2039 +0x61c fp=0x2055fdc sp=0x2055d6c pc=0x33c034 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.(*Server).Serve.gowrap3() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:3285 +0x38 fp=0x2055fec sp=0x2055fdc pc=0x341688 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2055fec sp=0x2055fec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by net/http.(*Server).Serve in goroutine 36 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:3285 +0x468 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 106 gp=0x2133b08 m=nil [select]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e4134, 0x0, 0x9, 0x3, 0x1) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x22e5ea8 sp=0x22e5e94 pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.selectgo(0x22e5fa4, 0x22e5f6c, 0x0, 0x0, 0x5, 0x1) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/select.go:327 +0xaf0 fp=0x22e5f48 sp=0x22e5ea8 pc=0x70e78 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: nhooyr.io/websocket.(*Conn).timeoutLoop(0x2598288) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:153 +0x10c fp=0x22e5fe4 sp=0x22e5f48 pc=0x474738 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: nhooyr.io/websocket.newConn.gowrap1() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x28 fp=0x22e5fec sp=0x22e5fe4 pc=0x47432c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x22e5fec sp=0x22e5fec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by nhooyr.io/websocket.newConn in goroutine 89 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x544 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 267714 gp=0x23ecd88 m=nil [chan receive]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e3f90, 0x2302230, 0xe, 0x7, 0x2) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x21c0bb0 sp=0x21c0b9c pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.chanrecv(0x2302200, 0x21c0c7c, 0x1) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/chan.go:583 +0x4b0 fp=0x21c0bec sp=0x21c0bb0 pc=0x20078 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.chanrecv1(0x2302200, 0x21c0c7c) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/chan.go:442 +0x20 fp=0x21c0c00 sp=0x21c0bec pc=0x1fb98 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: main.(*ConcreteApiServer).handleRequest(0x211c300, {{0x79134a, 0x4}, {0x6eba88, 0x2122228}, 0x2302200}, {0x886dec, 0x20a60a8}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/cmd/daemon/api_server.go:319 +0x74 fp=0x21c0c8c sp=0x21c0c00 pc=0x631f94 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: main.(*ConcreteApiServer).serve.func4({0x886dec, 0x20a60a8}, 0x20a6008) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/cmd/daemon/api_server.go:412 +0x148 fp=0x21c0ccc sp=0x21c0c8c pc=0x634b60 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.HandlerFunc.ServeHTTP(0x209a258, {0x886dec, 0x20a60a8}, 0x20a6008) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:2166 +0x34 fp=0x21c0cdc sp=0x21c0ccc pc=0x33d7f4 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.(*ServeMux).ServeHTTP(0x20b4880, {0x886dec, 0x20a60a8}, 0x20a6008) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:2683 +0x208 fp=0x21c0d18 sp=0x21c0cdc pc=0x33f654 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: main.(*ConcreteApiServer).serve.(*Cors).Handler.func19({0x886dec, 0x20a60a8}, 0x20a6008) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /src/.gocache/mod/github.com/rs/cors@v1.11.1/cors.go:289 +0x1f8 fp=0x21c0d40 sp=0x21c0d18 pc=0x633388 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.HandlerFunc.ServeHTTP(0x20be590, {0x886dec, 0x20a60a8}, 0x20a6008) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:2166 +0x34 fp=0x21c0d50 sp=0x21c0d40 pc=0x33d7f4 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.serverHandler.ServeHTTP({0x20a7cc8}, {0x886dec, 0x20a60a8}, 0x20a6008) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:3137 +0xe0 fp=0x21c0d6c sp=0x21c0d50 pc=0x340de4 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.(*conn).serve(0x20c6a20, {0x887510, 0x209e3a8}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:2039 +0x61c fp=0x21c0fdc sp=0x21c0d6c pc=0x33c034 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.(*Server).Serve.gowrap3() Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:3285 +0x38 fp=0x21c0fec sp=0x21c0fdc pc=0x341688 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x21c0fec sp=0x21c0fec pc=0x93d6c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: created by net/http.(*Server).Serve in goroutine 36 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:3285 +0x468 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: goroutine 258495 gp=0x2173d48 m=nil [IO wait]: Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e40f0, 0x74f82788, 0x2, 0x2, 0x5) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2526ad4 sp=0x2526ac0 pc=0x5d0c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: runtime.netpollblock(0x74f82778, 0x72, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/netpoll.go:573 +0x100 fp=0x2526aec sp=0x2526ad4 pc=0x548cc Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.runtime_pollWait(0x74f82778, 0x72) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/netpoll.go:345 +0x54 fp=0x2526b00 sp=0x2526aec pc=0x8f4a8 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*pollDesc).wait(0x207f238, 0x72, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x2526b14 sp=0x2526b00 pc=0x10a318 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*pollDesc).waitRead(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: internal/poll.(*FD).Read(0x207f220, {0x253d000, 0x1000, 0x1000}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_unix.go:164 +0x238 fp=0x2526b5c sp=0x2526b14 pc=0x10b504 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net.(*netFD).Read(0x207f220, {0x253d000, 0x1000, 0x1000}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/fd_posix.go:55 +0x38 fp=0x2526b88 sp=0x2526b5c pc=0x17c5d0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net.(*conn).Read(0x21019e8, {0x253d000, 0x1000, 0x1000}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/net.go:179 +0x48 fp=0x2526bb4 sp=0x2526b88 pc=0x18caec Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net.(*TCPConn).Read(0x21019e8, {0x253d000, 0x1000, 0x1000}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: :1 +0x44 fp=0x2526bd4 sp=0x2526bb4 pc=0x19fd40 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: crypto/tls.(*atLeastReader).Read(0x230ca90, {0x253d000, 0x1000, 0x1000}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/crypto/tls/conn.go:806 +0x78 fp=0x2526c00 sp=0x2526bd4 pc=0x27c680 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: bytes.(*Buffer).ReadFrom(0x213418c, {0x883674, 0x230ca90}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/bytes/buffer.go:211 +0xa4 fp=0x2526c3c sp=0x2526c00 pc=0x139bd0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: crypto/tls.(*Conn).readFromUntil(0x2134008, {0x882848, 0x21019e8}, 0x5) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/crypto/tls/conn.go:828 +0xd4 fp=0x2526c64 sp=0x2526c3c pc=0x27c8dc Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: crypto/tls.(*Conn).readRecordOrCCS(0x2134008, 0x0) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/crypto/tls/conn.go:626 +0x134 fp=0x2526dc8 sp=0x2526c64 pc=0x279fdc Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: crypto/tls.(*Conn).readRecord(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/crypto/tls/conn.go:588 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: crypto/tls.(*Conn).Read(0x2134008, {0x2ad7000, 0x1000, 0x1000}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/crypto/tls/conn.go:1370 +0x15c fp=0x2526df8 sp=0x2526dc8 pc=0x27fe4c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: bufio.(*Reader).Read(0x2464bd0, {0x21a20a4, 0x9, 0x9}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/bufio/bufio.go:241 +0x214 fp=0x2526e1c sp=0x2526df8 pc=0x2be440 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: io.ReadAtLeast({0x882a3c, 0x2464bd0}, {0x21a20a4, 0x9, 0x9}, 0x9) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/io/io.go:335 +0x90 fp=0x2526e48 sp=0x2526e1c pc=0x1042c0 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: io.ReadFull(...) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/io/io.go:354 Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.http2readFrameHeader({0x21a20a4, 0x9, 0x9}, {0x882a3c, 0x2464bd0}) Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/h2_bundle.go:1638 +0x54 fp=0x2526e70 sp=0x2526e48 pc=0x2f733c Jan 10 16:41:58 my-volumio-3 go-librespot[1572]: net/http.(*http2Framer).ReadFrame(0x21a2080) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/h2_bundle.go:1902 +0x88 fp=0x2526eec sp=0x2526e70 pc=0x2f7ad4 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: net/http.(*http2clientConnReadLoop).run(0x2526fdc) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/h2_bundle.go:9334 +0x150 fp=0x2526fa4 sp=0x2526eec pc=0x31c2f0 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: net/http.(*http2ClientConn).readLoop(0x2192108) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/h2_bundle.go:9229 +0x68 fp=0x2526fe4 sp=0x2526fa4 pc=0x31b7e4 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: net/http.(*http2Transport).newClientConn.gowrap1() Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/h2_bundle.go:7879 +0x28 fp=0x2526fec sp=0x2526fe4 pc=0x314830 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2526fec sp=0x2526fec pc=0x93d6c Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: created by net/http.(*http2Transport).newClientConn in goroutine 258494 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/h2_bundle.go:7879 +0xcb0 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: goroutine 148865 gp=0x228b0e8 m=nil [IO wait]: Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e40f0, 0x74f82968, 0x2, 0x2, 0x5) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x21bfafc sp=0x21bfae8 pc=0x5d0c0 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: runtime.netpollblock(0x74f82958, 0x72, 0x0) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/netpoll.go:573 +0x100 fp=0x21bfb14 sp=0x21bfafc pc=0x548cc Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: internal/poll.runtime_pollWait(0x74f82958, 0x72) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/netpoll.go:345 +0x54 fp=0x21bfb28 sp=0x21bfb14 pc=0x8f4a8 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: internal/poll.(*pollDesc).wait(0x20e4298, 0x72, 0x0) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x21bfb3c sp=0x21bfb28 pc=0x10a318 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: internal/poll.(*pollDesc).waitRead(...) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: internal/poll.(*FD).Read(0x20e4280, {0x26e0000, 0xa000, 0xa000}) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_unix.go:164 +0x238 fp=0x21bfb84 sp=0x21bfb3c pc=0x10b504 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: net.(*netFD).Read(0x20e4280, {0x26e0000, 0xa000, 0xa000}) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/fd_posix.go:55 +0x38 fp=0x21bfbb0 sp=0x21bfb84 pc=0x17c5d0 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: net.(*conn).Read(0x2c48230, {0x26e0000, 0xa000, 0xa000}) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/net.go:179 +0x48 fp=0x21bfbdc sp=0x21bfbb0 pc=0x18caec Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: net.(*TCPConn).Read(0x2c48230, {0x26e0000, 0xa000, 0xa000}) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: :1 +0x44 fp=0x21bfbfc sp=0x21bfbdc pc=0x19fd40 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: crypto/tls.(*atLeastReader).Read(0x2512370, {0x26e0000, 0xa000, 0xa000}) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/crypto/tls/conn.go:806 +0x78 fp=0x21bfc28 sp=0x21bfbfc pc=0x27c680 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: bytes.(*Buffer).ReadFrom(0x219818c, {0x883674, 0x2512370}) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/bytes/buffer.go:211 +0xa4 fp=0x21bfc64 sp=0x21bfc28 pc=0x139bd0 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: crypto/tls.(*Conn).readFromUntil(0x2198008, {0x882848, 0x2c48230}, 0x5) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/crypto/tls/conn.go:828 +0xd4 fp=0x21bfc8c sp=0x21bfc64 pc=0x27c8dc Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: crypto/tls.(*Conn).readRecordOrCCS(0x2198008, 0x0) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/crypto/tls/conn.go:626 +0x134 fp=0x21bfdf0 sp=0x21bfc8c pc=0x279fdc Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: crypto/tls.(*Conn).readRecord(...) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/crypto/tls/conn.go:588 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: crypto/tls.(*Conn).Read(0x2198008, {0x277f000, 0x1000, 0x1000}) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/crypto/tls/conn.go:1370 +0x15c fp=0x21bfe20 sp=0x21bfdf0 pc=0x27fe4c Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: net/http.(*persistConn).Read(0x213e378, {0x277f000, 0x1000, 0x1000}) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/transport.go:1977 +0x16c fp=0x21bfe54 sp=0x21bfe20 pc=0x3555cc Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: bufio.(*Reader).fill(0x2000120) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/bufio/bufio.go:110 +0x10c fp=0x21bfe78 sp=0x21bfe54 pc=0x2bddb4 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: bufio.(*Reader).Peek(0x2000120, 0x1) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/bufio/bufio.go:148 +0x68 fp=0x21bfe84 sp=0x21bfe78 pc=0x2bdf38 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: net/http.(*persistConn).readLoop(0x213e378) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/transport.go:2141 +0x194 fp=0x21bffe4 sp=0x21bfe84 pc=0x35615c Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: net/http.(*Transport).dialConn.gowrap2() Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/transport.go:1799 +0x28 fp=0x21bffec sp=0x21bffe4 pc=0x354a7c Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x21bffec sp=0x21bffec pc=0x93d6c Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: created by net/http.(*Transport).dialConn in goroutine 149715 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/transport.go:1799 +0x13f4 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: goroutine 149746 gp=0x22cd7a8 m=nil [select]: Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e4134, 0x0, 0x9, 0x3, 0x1) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x2520eb0 sp=0x2520e9c pc=0x5d0c0 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: runtime.selectgo(0x2520fac, 0x2520f78, 0x0, 0x0, 0x2, 0x1) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/select.go:327 +0xaf0 fp=0x2520f50 sp=0x2520eb0 pc=0x70e78 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: net/http.(*persistConn).writeLoop(0x213e378) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/transport.go:2444 +0xd0 fp=0x2520fe4 sp=0x2520f50 pc=0x357c1c Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: net/http.(*Transport).dialConn.gowrap3() Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/transport.go:1800 +0x28 fp=0x2520fec sp=0x2520fe4 pc=0x354a28 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x2520fec sp=0x2520fec pc=0x93d6c Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: created by net/http.(*Transport).dialConn in goroutine 149715 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/transport.go:1800 +0x1444 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: goroutine 267715 gp=0x258d688 m=nil [IO wait]: Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: runtime.gopark(0x7e40f0, 0x74f826e8, 0x2, 0x2, 0x5) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/proc.go:402 +0x104 fp=0x24c16b4 sp=0x24c16a0 pc=0x5d0c0 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: runtime.netpollblock(0x74f826d8, 0x72, 0x0) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/netpoll.go:573 +0x100 fp=0x24c16cc sp=0x24c16b4 pc=0x548cc Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: internal/poll.runtime_pollWait(0x74f826d8, 0x72) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/netpoll.go:345 +0x54 fp=0x24c16e0 sp=0x24c16cc pc=0x8f4a8 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: internal/poll.(*pollDesc).wait(0x23f1328, 0x72, 0x0) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:84 +0x30 fp=0x24c16f4 sp=0x24c16e0 pc=0x10a318 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: internal/poll.(*pollDesc).waitRead(...) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_poll_runtime.go:89 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: internal/poll.(*FD).Read(0x23f1310, {0x243526d, 0x1, 0x1}) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/internal/poll/fd_unix.go:164 +0x238 fp=0x24c173c sp=0x24c16f4 pc=0x10b504 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: net.(*netFD).Read(0x23f1310, {0x243526d, 0x1, 0x1}) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/fd_posix.go:55 +0x38 fp=0x24c1768 sp=0x24c173c pc=0x17c5d0 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: net.(*conn).Read(0x2c49918, {0x243526d, 0x1, 0x1}) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/net.go:179 +0x48 fp=0x24c1794 sp=0x24c1768 pc=0x18caec Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: net.(*TCPConn).Read(0x2c49918, {0x243526d, 0x1, 0x1}) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: :1 +0x44 fp=0x24c17b4 sp=0x24c1794 pc=0x19fd40 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: net/http.(*connReader).backgroundRead(0x2435260) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:681 +0x40 fp=0x24c17e4 sp=0x24c17b4 pc=0x335cfc Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: net/http.(*connReader).startBackgroundRead.gowrap2() Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:677 +0x28 fp=0x24c17ec sp=0x24c17e4 pc=0x335c34 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: runtime.goexit({}) Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/runtime/asm_arm.s:859 +0x4 fp=0x24c17ec sp=0x24c17ec pc=0x93d6c Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: created by net/http.(*connReader).startBackgroundRead in goroutine 267714 Jan 10 16:41:59 my-volumio-3 go-librespot[1572]: /usr/local/go/src/net/http/server.go:677 +0x160 Jan 10 16:41:59 my-volumio-3 go-librespot[1566]: Aborted Jan 10 16:42:00 my-volumio-3 systemd[1]: setdatetime-helper.service: Deactivated successfully. Jan 10 16:42:00 my-volumio-3 systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Jan 10 16:42:01 my-volumio-3 volumio[1239]: info: Initializing connection to go-librespot Websocket Jan 10 16:42:01 my-volumio-3 volumio[1239]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 10 16:42:02 my-volumio-3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 10 16:42:02 my-volumio-3 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 10 16:42:02 my-volumio-3 systemd[1]: go-librespot-daemon.service: Consumed 1min 9.575s CPU time. Jan 10 16:42:02 my-volumio-3 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 10 16:42:02 my-volumio-3 go-librespot[4886]: go-librespot daemon starting... Jan 10 16:42:02 my-volumio-3 go-librespot[4887]: time="2026-01-10T16:42:02+05:00" level=info msg="running go-librespot 0.4.0" Jan 10 16:42:02 my-volumio-3 go-librespot[4887]: time="2026-01-10T16:42:02+05:00" level=debug msg="app state loaded" Jan 10 16:42:02 my-volumio-3 go-librespot[4887]: time="2026-01-10T16:42:02+05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 10 16:42:02 my-volumio-3 go-librespot[4887]: time="2026-01-10T16:42:02+05:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Jan 10 16:42:02 my-volumio-3 go-librespot[4887]: time="2026-01-10T16:42:02+05:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Jan 10 16:42:02 my-volumio-3 go-librespot[4887]: time="2026-01-10T16:42:02+05:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Jan 10 16:42:02 my-volumio-3 go-librespot[4887]: time="2026-01-10T16:42:02+05:00" level=info msg="zeroconf server listening on port 34647" Jan 10 16:42:03 my-volumio-3 go-librespot[4887]: time="2026-01-10T16:42:03+05:00" level=debug msg="obtained new client token: AAAHN4zYt8GomFKe8CwjpJ+YgT2ylQSPQaG8bBNUoNzwuhWLlyql6tN4f6+k3lOlgMh0SRjpyafVLNy4/C47bgRN6tO2R7MkjMdZO32L0GqsVVTBAbTZT9zn5o/rWjBPGmsUkWUd+O6ZPm80yNVDazShAbrF8ItpYObemxULBaLjEfPGaUD4JIIiCnDv3X8T1PotvaUlkuuOzflZ62T5tEv1pvsIR+ahZJLW+QvIXIQ7HaxlWM+XGazj" Jan 10 16:42:03 my-volumio-3 go-librespot[4887]: time="2026-01-10T16:42:03+05:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 10 16:42:04 my-volumio-3 go-librespot[4887]: time="2026-01-10T16:42:04+05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.11.181:34576->104.199.65.9:4070: read: connection reset by peer" Jan 10 16:42:04 my-volumio-3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 10 16:42:04 my-volumio-3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 10 16:42:04 my-volumio-3 volumio[1239]: info: Initializing connection to go-librespot Websocket Jan 10 16:42:04 my-volumio-3 volumio[1239]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 10 16:42:07 my-volumio-3 systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 10 16:42:07 my-volumio-3 systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 10 16:42:07 my-volumio-3 systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 10 16:42:07 my-volumio-3 go-librespot[4898]: go-librespot daemon starting... Jan 10 16:42:07 my-volumio-3 go-librespot[4899]: time="2026-01-10T16:42:07+05:00" level=info msg="running go-librespot 0.4.0" Jan 10 16:42:07 my-volumio-3 go-librespot[4899]: time="2026-01-10T16:42:07+05:00" level=debug msg="app state loaded" Jan 10 16:42:07 my-volumio-3 go-librespot[4899]: time="2026-01-10T16:42:07+05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 10 16:42:07 my-volumio-3 volumio[1239]: info: Initializing connection to go-librespot Websocket Jan 10 16:42:07 my-volumio-3 go-librespot[4899]: time="2026-01-10T16:42:07+05:00" level=debug msg="new websocket client" Jan 10 16:42:07 my-volumio-3 volumio[1239]: info: Connection to go-librespot Websocket established Jan 10 16:42:08 my-volumio-3 go-librespot[4899]: time="2026-01-10T16:42:08+05:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 10 16:42:08 my-volumio-3 go-librespot[4899]: time="2026-01-10T16:42:08+05:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 10 16:42:08 my-volumio-3 go-librespot[4899]: time="2026-01-10T16:42:08+05:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 10 16:42:08 my-volumio-3 go-librespot[4899]: time="2026-01-10T16:42:08+05:00" level=info msg="zeroconf server listening on port 40629" Jan 10 16:42:08 my-volumio-3 go-librespot[4899]: time="2026-01-10T16:42:08+05:00" level=debug msg="obtained new client token: AADUzxxjFBJcwQtRsNEMGwz4e1g+sRLJKEjPyb0L1FdouohwDAjLbH7UMuJjOYQVH13c8LqztgxRCyAZQeymjmISE1AmWJIvPzX577HuXTj4e0sux2razCni9+ZNc6bqx+tNCjqvCKxVbdVnz0dUj9y0J4/oema5weeaehIq+tI6NLDmoqgheQsMCU8E5pLrV2IivNZE4t7sbJ2gNmi5MrBy3+85rHpAbcv3Ex5q/vwJ+eSAdhGFB58kRo4=" Jan 10 16:42:09 my-volumio-3 go-librespot[4899]: time="2026-01-10T16:42:09+05:00" level=debug msg="connected to ap-gew1.spotify.com:4070" Jan 10 16:42:09 my-volumio-3 go-librespot[4899]: time="2026-01-10T16:42:09+05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 10 16:42:09 my-volumio-3 volumio[1239]: info: Connection to go-librespot Websocket closed Jan 10 16:42:09 my-volumio-3 systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 10 16:42:09 my-volumio-3 systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 10 16:42:11 my-volumio-3 volumio[1239]: info: Getting Spotify volume Jan 10 16:42:11 my-volumio-3 volumio[1239]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 10 16:42:11 my-volumio-3 volumio[1239]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 10 16:42:11 my-volumio-3 volumio[1239]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 10 16:42:11 my-volumio-3 volumio[1239]: errno: -111, Jan 10 16:42:11 my-volumio-3 volumio[1239]: code: 'ECONNREFUSED', Jan 10 16:42:11 my-volumio-3 volumio[1239]: syscall: 'connect', Jan 10 16:42:11 my-volumio-3 volumio[1239]: address: '127.0.0.1', Jan 10 16:42:11 my-volumio-3 volumio[1239]: port: 9879, Jan 10 16:42:11 my-volumio-3 volumio[1239]: response: undefined Jan 10 16:42:11 my-volumio-3 volumio[1239]: } Jan 10 16:42:11 my-volumio-3 volumio[1239]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 10 16:42:11 my-volumio-3 sudo[4935]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-10 16:41' Jan 10 16:42:11 my-volumio-3 sudo[4935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"