-- Logs begin at Sun 2025-02-16 19:44:29 UTC, end at Sun 2025-02-16 20:54:33 UTC. -- Feb 16 20:53:00 znt go-librespot[1672]: time="2025-02-16T20:53:00Z" level=warning msg="failed fetching new endpoint for accesspoint" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 16 20:53:00 znt go-librespot[1672]: time="2025-02-16T20:53:00Z" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp: lookup ap-gew4.spotify.com: device or resource busy), retrying with a different AP" Feb 16 20:53:00 znt go-librespot[1672]: time="2025-02-16T20:53:00Z" level=warning msg="failed fetching new endpoint for accesspoint" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 16 20:53:00 znt go-librespot[1672]: time="2025-02-16T20:53:00Z" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp: lookup ap-gew4.spotify.com: device or resource busy), retrying with a different AP" Feb 16 20:53:00 znt go-librespot[1672]: time="2025-02-16T20:53:00Z" level=warning msg="failed fetching new endpoint for accesspoint" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 16 20:53:00 znt go-librespot[1672]: time="2025-02-16T20:53:00Z" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp: lookup ap-gew4.spotify.com: device or resource busy), retrying with a different AP" Feb 16 20:53:00 znt go-librespot[1672]: time="2025-02-16T20:53:00Z" level=warning msg="failed fetching new endpoint for accesspoint" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 16 20:53:00 znt go-librespot[1672]: time="2025-02-16T20:53:00Z" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp: lookup ap-gew4.spotify.com: device or resource busy), retrying with a different AP" Feb 16 20:53:00 znt go-librespot[1672]: time="2025-02-16T20:53:00Z" level=warning msg="failed fetching new endpoint for accesspoint" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 16 20:53:00 znt go-librespot[1672]: time="2025-02-16T20:53:00Z" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp: lookup ap-gew4.spotify.com: device or resource busy), retrying with a different AP" Feb 16 20:53:00 znt go-librespot[1672]: time="2025-02-16T20:53:00Z" level=warning msg="failed fetching new endpoint for accesspoint" error="failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 16 20:53:01 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: last_100 , handleBrowseUri Feb 16 20:53:01 znt volumio[1183]: info: Preload queue cleared Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:6FGR7ykXl8buAyT0kMfdB9 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:1LiW4oFjovnHw6bajYmR3H Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:5KuuAcWRtfEkVgWtm7o2th Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:5h8Drc5We5CdOITzuFHx17 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:4jmrg48Cp8EDmOLZpkXDw9 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:2WtsALda64u2bW5jpiMRhD Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:3XWelzCZPM8J5Swsgp8eJO Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:0MWlqwA1YUpM00tVxD2gk1 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:609cexFubQ8JQ5u20Jbbkx Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:6hvo5KPU0Pk1Lc5vo6iVQB Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:0KMiWpGnbzjs4eSGBvVr3o Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:2zYw55nMC7AdYrvLl902yV Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:7hTocMxPJylk1oFJc9njDy Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:1dC5lHCIGtVEZcCRjk0OaB Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:2IWJZGJ27vkrbXoUPIACXc Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:7yOsFuEskR1KRsHCy4Np6s Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:5NeG0oiSG4rnKvtVxtkUxf Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:4svSLhdrK5vAPdASXmIJxh Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:03gwoo31Y3t7K4Fb36Q6v0 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:1dVjCsGv4KuHrf0Y2NwyCK Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:6CQDJortuzgJgxnX3FcYfO Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:3VkFB4F9WZbpEjmFuesaBR Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:6iO7BdcRP6Anly23OES1eT Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:24zdi7KrUsalCbjUoDX5ul Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:49oauJ9kLOYaeFQFWsbUwo Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:5FMjkiJp012O2T8gTzGFPr Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:0iDHfRNAxWdEJSUZ23l9iF Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:7nqmjUf6rmamJt02nZa4a4 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:3KbYGEZFEj6OYZ8KI2lMQy Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:4NwY0J5QurkzovHm1VEvDy Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:1pBI0CumuXGLAsvmBf3HSu Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:1aat6Gzqaxc3AEJVxTJxjc Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:0wH3V4K9UPjUOGRcYpCQEj Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:2fo3itviTrZPgfsygMuQMj Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:1jFyGu7sdxuUgeQ1Skq0cc Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:5zjzdH9KGAxB75Pyu3j0tc Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:6riq2aRoEYbdrEt80RLqK9 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:6hpAbOImGVRTrrwRDmZOTY Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:35kQ9ZpF377PSJs8Bp9gtn Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:72YAQ49UBBDMEQxE3KXxBY Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:7FCXRr3TCDiNn79SrUaIK2 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:4Kw9KysyP6y6YGoEffYT3S Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: upnp/folder/http://192.168.188.21:50001/ContentDirectory/control@22$483 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:0ejJSN0yCHGkyC4ZHgWzpb Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:6JgtkXohSi6uBYwqdy89DP Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:6aeWtey0Q1ZLpjQny5cyU6 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:0cAdo09bcV93qw2UzaiMo4 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:126SHpoZRqPs8CX6wWLo46 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:3yf0NDUue2VqsWpxDYLUPc Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:1wJxSYpxvufStONDfPfEMp Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:6AIaPepPICSN9eWlpO7tEA Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:4rkR35wElxIvUDmD2RbrOz Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:1Hrd97tIWFukJzDy2ZKeLn Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:3WPB2SFZen5FyVYMj8cqf9 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:0Se6Ly56UJ9TUW9W1bTFbV Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:7FFjAt14A3Rl4ApoqvrBec Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:5u9xarAztF6fYkWxnlv1GC Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:7a6LCZEuPRjP91PKkCYRlS Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:4y6xQW6De7HXu9X8TGYHwx Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:0VXqMR0b6aEvdW3novJ8bw Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:5j9M4piQrZhUDg0aOQ1EyN Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:4FEojeJH30lXGFrU0sAlpo Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:2ZGKkSXDEZ1i8Zmzmkn9px Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:4e0VDn9a6LFT35u2H8v9uo Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:61me61UGavnApjgG2MUIKs Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:7lOaeWlI5YaA6yLignuxQP Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:2JY4AMYnEPt49f7AyyxI9i Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:5Ks0fikFSkpCILRYdlCRUD Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:3VygbLR70zCdxanglfcb30 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:168yC2HtY8gBosw9n17cWU Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:44E9lhFeSXkAd0kWqfnDn1 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:5C90brGfAc9tLXCCJs9DLt Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:6A23a94f2xpbu3Un9L9o5T Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:7cyI0tN3fT3qlgyt3SDw0k Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:5583e6W6aXpsV5veZxcfvE Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:6SkHKuXMa7Z8OqOd4F11aA Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:4Wh9I9F0KA07GsXwWdC9p9 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:3l3cOYICR4o1mObp2nS19X Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:4t9dDzKD5gbjcOwWse2Up1 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:1Sv8l0pZa6r8TUSQCGM8iU Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:4CqhUMO6iyJo1BClPXzJq1 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:4JXtnw6Mu4d2DGmPwYqa60 Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:7D6FRgePpcrzJSlqgFqJpX Feb 16 20:53:01 znt volumio[1183]: info: Preloading song: spotify:track:0oxyw2edKA7JJbbeFh84h3 Feb 16 20:53:01 znt volumio[1183]: info: Exploding uri spotify:track:6FGR7ykXl8buAyT0kMfdB9 in service spop Feb 16 20:53:01 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:6FGR7ykXl8buAyT0kMfdB9 Feb 16 20:53:01 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:6FGR7ykXl8buAyT0kMfdB9 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:01 znt volumio[1183]: info: Exploding uri spotify:track:1LiW4oFjovnHw6bajYmR3H in service spop Feb 16 20:53:01 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:1LiW4oFjovnHw6bajYmR3H Feb 16 20:53:01 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:1LiW4oFjovnHw6bajYmR3H from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:01 znt volumio[1183]: info: Exploding uri spotify:track:5KuuAcWRtfEkVgWtm7o2th in service spop Feb 16 20:53:01 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:5KuuAcWRtfEkVgWtm7o2th Feb 16 20:53:01 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:5KuuAcWRtfEkVgWtm7o2th from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:01 znt volumio[1183]: info: Exploding uri spotify:track:5h8Drc5We5CdOITzuFHx17 in service spop Feb 16 20:53:01 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:5h8Drc5We5CdOITzuFHx17 Feb 16 20:53:01 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:5h8Drc5We5CdOITzuFHx17 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:01 znt volumio[1183]: info: Exploding uri spotify:track:4jmrg48Cp8EDmOLZpkXDw9 in service spop Feb 16 20:53:01 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:4jmrg48Cp8EDmOLZpkXDw9 Feb 16 20:53:01 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:4jmrg48Cp8EDmOLZpkXDw9 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:2WtsALda64u2bW5jpiMRhD in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:2WtsALda64u2bW5jpiMRhD Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:2WtsALda64u2bW5jpiMRhD from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:3XWelzCZPM8J5Swsgp8eJO in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:3XWelzCZPM8J5Swsgp8eJO Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:3XWelzCZPM8J5Swsgp8eJO from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:0MWlqwA1YUpM00tVxD2gk1 in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:0MWlqwA1YUpM00tVxD2gk1 Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:0MWlqwA1YUpM00tVxD2gk1 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:609cexFubQ8JQ5u20Jbbkx in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:609cexFubQ8JQ5u20Jbbkx Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:609cexFubQ8JQ5u20Jbbkx from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:6hvo5KPU0Pk1Lc5vo6iVQB in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:6hvo5KPU0Pk1Lc5vo6iVQB Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:6hvo5KPU0Pk1Lc5vo6iVQB from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:0KMiWpGnbzjs4eSGBvVr3o in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:0KMiWpGnbzjs4eSGBvVr3o Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:0KMiWpGnbzjs4eSGBvVr3o from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:2zYw55nMC7AdYrvLl902yV in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:2zYw55nMC7AdYrvLl902yV Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:2zYw55nMC7AdYrvLl902yV from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:7hTocMxPJylk1oFJc9njDy in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:7hTocMxPJylk1oFJc9njDy Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:7hTocMxPJylk1oFJc9njDy from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:1dC5lHCIGtVEZcCRjk0OaB in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:1dC5lHCIGtVEZcCRjk0OaB Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:1dC5lHCIGtVEZcCRjk0OaB from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:2IWJZGJ27vkrbXoUPIACXc in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:2IWJZGJ27vkrbXoUPIACXc Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:2IWJZGJ27vkrbXoUPIACXc from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:7yOsFuEskR1KRsHCy4Np6s in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:7yOsFuEskR1KRsHCy4Np6s Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:7yOsFuEskR1KRsHCy4Np6s from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:5NeG0oiSG4rnKvtVxtkUxf in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:5NeG0oiSG4rnKvtVxtkUxf Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:5NeG0oiSG4rnKvtVxtkUxf from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:4svSLhdrK5vAPdASXmIJxh in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:4svSLhdrK5vAPdASXmIJxh Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:4svSLhdrK5vAPdASXmIJxh from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:03gwoo31Y3t7K4Fb36Q6v0 in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:03gwoo31Y3t7K4Fb36Q6v0 Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:03gwoo31Y3t7K4Fb36Q6v0 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:1dVjCsGv4KuHrf0Y2NwyCK in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:1dVjCsGv4KuHrf0Y2NwyCK Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:1dVjCsGv4KuHrf0Y2NwyCK from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:6CQDJortuzgJgxnX3FcYfO in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:6CQDJortuzgJgxnX3FcYfO Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:6CQDJortuzgJgxnX3FcYfO from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:3VkFB4F9WZbpEjmFuesaBR in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:3VkFB4F9WZbpEjmFuesaBR Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:3VkFB4F9WZbpEjmFuesaBR from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:6iO7BdcRP6Anly23OES1eT in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:6iO7BdcRP6Anly23OES1eT Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:6iO7BdcRP6Anly23OES1eT from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:24zdi7KrUsalCbjUoDX5ul in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:24zdi7KrUsalCbjUoDX5ul Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:24zdi7KrUsalCbjUoDX5ul from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:02 znt volumio[1183]: info: Exploding uri spotify:track:49oauJ9kLOYaeFQFWsbUwo in service spop Feb 16 20:53:02 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:49oauJ9kLOYaeFQFWsbUwo Feb 16 20:53:02 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:49oauJ9kLOYaeFQFWsbUwo from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt go-librespot[1672]: time="2025-02-16T20:53:03Z" level=error msg="did not receive last pong ack from accesspoint, 359s passed" Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:5FMjkiJp012O2T8gTzGFPr in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:5FMjkiJp012O2T8gTzGFPr Feb 16 20:53:03 znt go-librespot[1672]: panic: runtime error: invalid memory address or nil pointer dereference Feb 16 20:53:03 znt go-librespot[1672]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x18 pc=0x824a89] Feb 16 20:53:03 znt go-librespot[1672]: goroutine 34 gp=0xc0001701c0 m=3 mp=0xc000063008 [running]: Feb 16 20:53:03 znt go-librespot[1672]: panic({0x98d8a0?, 0xeac160?}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/panic.go:779 +0x158 fp=0xc00024fee0 sp=0xc00024fe30 pc=0x441a58 Feb 16 20:53:03 znt go-librespot[1672]: runtime.panicmem(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/panic.go:261 Feb 16 20:53:03 znt go-librespot[1672]: runtime.sigpanic() Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/signal_unix.go:881 +0x378 fp=0xc00024ff40 sp=0xc00024fee0 pc=0x45a338 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/ap.(*Accesspoint).pongAckTicker(0xc0002625b0) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:328 +0x189 fp=0xc00024ffc8 sp=0xc00024ff40 pc=0x824a89 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/ap.NewAccesspoint.gowrap1() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:67 +0x25 fp=0xc00024ffe0 sp=0xc00024ffc8 pc=0x822c25 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00024ffe8 sp=0xc00024ffe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by go-librespot/ap.NewAccesspoint in goroutine 1 Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:67 +0x159 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 1 gp=0xc0000061c0 m=nil [select, 68 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0xc000045c58?, 0x2?, 0x18?, 0xd?, 0xc000045bf4?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc0000d1a88 sp=0xc0000d1a68 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.selectgo(0xc0000d1c58, 0xc000045bf0, 0xc000045c40?, 0x0, 0x30?, 0x1) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0x725 fp=0xc0000d1ba8 sp=0xc0000d1a88 pc=0x456825 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/zeroconf.(*Zeroconf).Serve(0xc000132510, 0xc0000d1d50) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/zeroconf/zeroconf.go:268 +0x2a6 fp=0xc0000d1cf0 sp=0xc0000d1ba8 pc=0x8b9846 Feb 16 20:53:03 znt go-librespot[1672]: main.(*App).withAppPlayer(0xc000036320, 0xc0000894c0) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:297 +0x493 fp=0xc0000d1dd0 sp=0xc0000d1cf0 pc=0x90a053 Feb 16 20:53:03 znt go-librespot[1672]: main.(*App).withCredentials(0xc000036320, {0x9b76a0, 0xc00007c660}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:171 +0x38c fp=0xc0000d1e90 sp=0xc0000d1dd0 pc=0x90982c Feb 16 20:53:03 znt go-librespot[1672]: main.(*App).SpotifyToken(...) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:131 Feb 16 20:53:03 znt go-librespot[1672]: main.main() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:466 +0x605 fp=0xc0000d1f50 sp=0xc0000d1e90 pc=0x90b545 Feb 16 20:53:03 znt go-librespot[1672]: runtime.main() Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:271 +0x29d fp=0xc0000d1fe0 sp=0xc0000d1f50 pc=0x44507d Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0000d1fe8 sp=0xc0000d1fe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 2 gp=0xc000006fc0 m=nil [force gc (idle), 3 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0x3a74ceb560e?, 0x0?, 0x0?, 0x0?, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc00005efa8 sp=0xc00005ef88 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.goparkunlock(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 Feb 16 20:53:03 znt go-librespot[1672]: runtime.forcegchelper() Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:326 +0xb3 fp=0xc00005efe0 sp=0xc00005efa8 pc=0x445333 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00005efe8 sp=0xc00005efe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by runtime.init.6 in goroutine 1 Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:314 +0x1a Feb 16 20:53:03 znt go-librespot[1672]: goroutine 3 gp=0xc000007180 m=nil [GC sweep wait]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0x1?, 0x0?, 0x0?, 0x0?, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc00005f780 sp=0xc00005f760 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.goparkunlock(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 Feb 16 20:53:03 znt go-librespot[1672]: runtime.bgsweep(0xc00007e000) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgcsweep.go:318 +0xdf fp=0xc00005f7c8 sp=0xc00005f780 pc=0x430a5f Feb 16 20:53:03 znt go-librespot[1672]: runtime.gcenable.gowrap1() Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:203 +0x25 fp=0xc00005f7e0 sp=0xc00005f7c8 pc=0x425365 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00005f7e8 sp=0xc00005f7e0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by runtime.gcenable in goroutine 1 Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:203 +0x66 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 4 gp=0xc000007340 m=nil [GC scavenge wait]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0x3f7e0e?, 0x35acc1?, 0x0?, 0x0?, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc00005ff78 sp=0xc00005ff58 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.goparkunlock(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 Feb 16 20:53:03 znt go-librespot[1672]: runtime.(*scavengerState).park(0xf03a20) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgcscavenge.go:425 +0x49 fp=0xc00005ffa8 sp=0xc00005ff78 pc=0x42e409 Feb 16 20:53:03 znt go-librespot[1672]: runtime.bgscavenge(0xc00007e000) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgcscavenge.go:658 +0x59 fp=0xc00005ffc8 sp=0xc00005ffa8 pc=0x42e9b9 Feb 16 20:53:03 znt go-librespot[1672]: runtime.gcenable.gowrap2() Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:204 +0x25 fp=0xc00005ffe0 sp=0xc00005ffc8 pc=0x425305 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:5FMjkiJp012O2T8gTzGFPr from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00005ffe8 sp=0xc00005ffe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by runtime.gcenable in goroutine 1 Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:204 +0xa5 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 5 gp=0xc000007880 m=nil [finalizer wait]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0x0?, 0xc0002b7ca0?, 0x50?, 0x41?, 0x1000000010?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc0004abe20 sp=0xc0004abe00 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.runfinq() Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mfinal.go:194 +0x107 fp=0xc0004abfe0 sp=0xc0004abe20 pc=0x4243a7 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0004abfe8 sp=0xc0004abfe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by runtime.createfing in goroutine 1 Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mfinal.go:164 +0x3d Feb 16 20:53:03 znt go-librespot[1672]: goroutine 6 gp=0xc000170000 m=nil [IO wait, 3 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0xc00004c008?, 0x0?, 0x0?, 0x0?, 0xc000071c18?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc000071be0 sp=0xc000071bc0 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.netpollblock(0xc000071c78?, 0x40e586?, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0xf7 fp=0xc000071c18 sp=0xc000071be0 pc=0x43e217 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.runtime_pollWait(0x7f61516b7e80, 0x72) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x85 fp=0xc000071c38 sp=0xc000071c18 pc=0x472185 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*pollDesc).wait(0x3?, 0x29d?, 0x0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x27 fp=0xc000071c60 sp=0xc000071c38 pc=0x4e15c7 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*pollDesc).waitRead(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*FD).Accept(0xc0000aab00) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:611 +0x2ac fp=0xc000071d08 sp=0xc000071c60 pc=0x4e696c Feb 16 20:53:03 znt go-librespot[1672]: net.(*netFD).accept(0xc0000aab00) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_unix.go:172 +0x29 fp=0xc000071dc0 sp=0xc000071d08 pc=0x65cfa9 Feb 16 20:53:03 znt go-librespot[1672]: net.(*TCPListener).accept(0xc00007c5c0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/tcpsock_posix.go:159 +0x1e fp=0xc000071de8 sp=0xc000071dc0 pc=0x672efe Feb 16 20:53:03 znt go-librespot[1672]: net.(*TCPListener).Accept(0xc00007c5c0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/tcpsock.go:327 +0x30 fp=0xc000071e18 sp=0xc000071de8 pc=0x6720f0 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*onceCloseListener).Accept(0xc0003d10e0?) Feb 16 20:53:03 znt go-librespot[1672]: :1 +0x24 fp=0xc000071e30 sp=0xc000071e18 pc=0x7f6fe4 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*Server).Serve(0xc000172000, {0xb1a640, 0xc00007c5c0}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3255 +0x33e fp=0xc000071f60 sp=0xc000071e30 pc=0x7d4f3e Feb 16 20:53:03 znt go-librespot[1672]: net/http.Serve(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2794 Feb 16 20:53:03 znt go-librespot[1672]: main.(*ApiServer).serve(0xc00008a480) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:470 +0x50e fp=0xc000071fc8 sp=0xc000071f60 pc=0x90260e Feb 16 20:53:03 znt go-librespot[1672]: main.NewApiServer.gowrap1() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:240 +0x25 fp=0xc000071fe0 sp=0xc000071fc8 pc=0x901d05 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000071fe8 sp=0xc000071fe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by main.NewApiServer in goroutine 1 Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:240 +0x1db Feb 16 20:53:03 znt go-librespot[1672]: goroutine 13 gp=0xc000170540 m=nil [GC worker (idle)]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0x3a74d660f31?, 0xc0003f92a0?, 0x1a?, 0xa?, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc000060750 sp=0xc000060730 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.gcBgMarkWorker() Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1310 +0xe5 fp=0xc0000607e0 sp=0xc000060750 pc=0x427445 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0000607e8 sp=0xc0000607e0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by runtime.gcBgMarkStartWorkers in goroutine 12 Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/mgc.go:1234 +0x1c Feb 16 20:53:03 znt go-librespot[1672]: goroutine 20 gp=0xc00026aa80 m=nil [IO wait, 4 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0xc000073d88?, 0x420d18?, 0x40?, 0xe2?, 0xc0001826e0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc000073d30 sp=0xc000073d10 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.netpollblock(0xb15ce0?, 0xec2d98?, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0xf7 fp=0xc000073d68 sp=0xc000073d30 pc=0x43e217 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.runtime_pollWait(0x7f61516b7b98, 0x72) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x85 fp=0xc000073d88 sp=0xc000073d68 pc=0x472185 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*pollDesc).wait(0xc0000ab400?, 0x41869b?, 0x0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x27 fp=0xc000073db0 sp=0xc000073d88 pc=0x4e15c7 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*pollDesc).waitRead(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*FD).RawRead(0xc0000ab400, 0xc0001826e0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:708 +0x12a fp=0xc000073e10 sp=0xc000073db0 pc=0x4e75ea Feb 16 20:53:03 znt go-librespot[1672]: net.(*rawConn).Read(0xc00004a0f8, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/rawconn.go:44 +0x36 fp=0xc000073e48 sp=0xc000073e10 pc=0x66df16 Feb 16 20:53:03 znt go-librespot[1672]: golang.org/x/net/internal/socket.(*Conn).recvMsg(0xc00045d9e0, 0xc0002a0180, 0x0) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/internal/socket/rawconn_msg.go:28 +0x144 fp=0xc000073ea0 sp=0xc000073e48 pc=0x85c404 Feb 16 20:53:03 znt go-librespot[1672]: golang.org/x/net/internal/socket.(*Conn).RecvMsg(...) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/internal/socket/socket.go:247 Feb 16 20:53:03 znt go-librespot[1672]: golang.org/x/net/ipv4.(*payloadHandler).ReadFrom(0xc0001ca5b0, {0xc000220000, 0x10000, 0x10000}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/ipv4/payload_cmsg.go:32 +0x4ae fp=0xc000073f48 sp=0xc000073ea0 pc=0x85fe8e Feb 16 20:53:03 znt go-librespot[1672]: github.com/grandcat/zeroconf.(*Server).recv4(0xc0001d2a20, 0xc0001ca5a0) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:254 +0xd0 fp=0xc000073fc0 sp=0xc000073f48 pc=0x8b4a70 Feb 16 20:53:03 znt go-librespot[1672]: github.com/grandcat/zeroconf.(*Server).mainloop.gowrap1() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:188 +0x25 fp=0xc000073fe0 sp=0xc000073fc0 pc=0x8b4705 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000073fe8 sp=0xc000073fe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by github.com/grandcat/zeroconf.(*Server).mainloop in goroutine 18 Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:188 +0x78 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 21 gp=0xc00026afc0 m=nil [IO wait, 68 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0xc00005c538?, 0x420d18?, 0x40?, 0x62?, 0xc0001ca730?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc000072ce0 sp=0xc000072cc0 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.netpollblock(0xb15ce0?, 0xec2d98?, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0xf7 fp=0xc000072d18 sp=0xc000072ce0 pc=0x43e217 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.runtime_pollWait(0x7f61516b7aa0, 0x72) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x85 fp=0xc000072d38 sp=0xc000072d18 pc=0x472185 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*pollDesc).wait(0xc0000ab480?, 0x41869b?, 0x0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x27 fp=0xc000072d60 sp=0xc000072d38 pc=0x4e15c7 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*pollDesc).waitRead(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*FD).RawRead(0xc0000ab480, 0xc0001ca730) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:708 +0x12a fp=0xc000072dc0 sp=0xc000072d60 pc=0x4e75ea Feb 16 20:53:03 znt go-librespot[1672]: net.(*rawConn).Read(0xc00004a180, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/rawconn.go:44 +0x36 fp=0xc000072df8 sp=0xc000072dc0 pc=0x66df16 Feb 16 20:53:03 znt go-librespot[1672]: golang.org/x/net/internal/socket.(*Conn).recvMsg(0xc00045da00, 0xc0001d2f00, 0x0) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/internal/socket/rawconn_msg.go:28 +0x144 fp=0xc000072e50 sp=0xc000072df8 pc=0x85c404 Feb 16 20:53:03 znt go-librespot[1672]: golang.org/x/net/internal/socket.(*Conn).RecvMsg(...) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/internal/socket/socket.go:247 Feb 16 20:53:03 znt go-librespot[1672]: golang.org/x/net/ipv6.(*payloadHandler).ReadFrom(0xc0001ca600, {0xc000210000, 0x10000, 0x10000}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/golang.org/x/net@v0.11.0/ipv6/payload_cmsg.go:32 +0x38d fp=0xc000072f48 sp=0xc000072e50 pc=0x86322d Feb 16 20:53:03 znt go-librespot[1672]: github.com/grandcat/zeroconf.(*Server).recv6(0xc0001d2a20, 0xc0001ca5f0) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:282 +0xd0 fp=0xc000072fc0 sp=0xc000072f48 pc=0x8b4c30 Feb 16 20:53:03 znt go-librespot[1672]: github.com/grandcat/zeroconf.(*Server).mainloop.gowrap2() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:191 +0x25 fp=0xc000072fe0 sp=0xc000072fc0 pc=0x8b46a5 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000072fe8 sp=0xc000072fe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by github.com/grandcat/zeroconf.(*Server).mainloop in goroutine 18 Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/grandcat/zeroconf@v1.0.0/server.go:191 +0xd9 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 56 gp=0xc00026b180 m=nil [select, 3 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0xc000421f88?, 0x3?, 0x90?, 0x1d?, 0xc000421eca?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc000421d68 sp=0xc000421d48 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.selectgo(0xc000421f88, 0xc000421ec4, 0xc0000f6c08?, 0x0, 0x0?, 0x1) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0x725 fp=0xc000421e88 sp=0xc000421d68 pc=0x456825 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/player.(*Player).manageLoop(0xc000347680) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/player/player.go:109 +0x1f4 fp=0xc000421fc8 sp=0xc000421e88 pc=0x83f3b4 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/player.NewPlayer.gowrap1() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/player/player.go:91 +0x25 fp=0xc000421fe0 sp=0xc000421fc8 pc=0x83f0a5 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000421fe8 sp=0xc000421fe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by go-librespot/player.NewPlayer in goroutine 1 Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/player/player.go:91 +0x219 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 55 gp=0xc00026b500 m=nil [select]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0xc0000d5f98?, 0x2?, 0xd0?, 0xc?, 0xc0000d5f54?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc0000d5df8 sp=0xc0000d5dd8 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.selectgo(0xc0000d5f98, 0xc0000d5f50, 0x0?, 0x0, 0xc0000d5f88?, 0x1) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0x725 fp=0xc0000d5f18 sp=0xc0000d5df8 pc=0x456825 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/dealer.(*Dealer).pingTicker(0xc000233080) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:107 +0x8f fp=0xc0000d5fc8 sp=0xc0000d5f18 pc=0x84dd0f Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/dealer.NewDealer.gowrap1() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:57 +0x25 fp=0xc0000d5fe0 sp=0xc0000d5fc8 pc=0x84d745 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0000d5fe8 sp=0xc0000d5fe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by go-librespot/dealer.NewDealer in goroutine 1 Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:57 +0x158 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 62 gp=0xc00026bdc0 m=nil [select]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0xc0000cfd70?, 0x2?, 0xd6?, 0xa2?, 0xc0000cfd1c?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc0000cfbc0 sp=0xc0000cfba0 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.selectgo(0xc0000cfd70, 0xc0000cfd18, 0x9547a0?, 0x0, 0xc00031d020?, 0x1) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0x725 fp=0xc0000cfce0 sp=0xc0000cfbc0 pc=0x456825 Feb 16 20:53:03 znt go-librespot[1672]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0xc0000cfe08?, {0xb19b98, 0xc00031d020}, 0x0, {0x0, 0x0?}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:112 +0x24f fp=0xc0000cfdd0 sp=0xc0000cfce0 pc=0x81708f Feb 16 20:53:03 znt go-librespot[1672]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer(0xc00037c620?, {0xb19b98?, 0xc00031d020?}, 0x991b00?, {0x0?, 0x0?}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:61 +0x5c fp=0xc0000cfe28 sp=0xc0000cfdd0 pc=0x816b7c Feb 16 20:53:03 znt go-librespot[1672]: github.com/cenkalti/backoff/v4.RetryNotify(...) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:49 Feb 16 20:53:03 znt go-librespot[1672]: github.com/cenkalti/backoff/v4.Retry(...) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:38 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/ap.(*Accesspoint).recvLoop(0xc0002625b0) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:289 +0x395 fp=0xc0000cffc8 sp=0xc0000cfe28 pc=0x824535 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/ap.(*Accesspoint).startReceiving.func1.gowrap1() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:240 +0x25 fp=0xc0000cffe0 sp=0xc0000cffc8 pc=0x824165 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0000cffe8 sp=0xc0000cffe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by go-librespot/ap.(*Accesspoint).startReceiving.func1 in goroutine 58 Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/ap/ap.go:240 +0x56 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 58 gp=0xc00035a000 m=nil [select, 3 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0xc000044198?, 0x4?, 0x18?, 0xd?, 0xc000044128?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc000043fd0 sp=0xc000043fb0 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.selectgo(0xc000044198, 0xc000044120, 0xedf44463d?, 0x0, 0x41dcba?, 0x1) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0x725 fp=0xc0000440f0 sp=0xc000043fd0 pc=0x456825 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*http2ClientConn).RoundTrip(0xc00019f680, 0xc0001807e0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:8354 +0x434 fp=0xc000044230 sp=0xc0000440f0 pc=0x7ab314 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*http2Transport).RoundTripOpt(0xc0001323f0, 0xc0001807e0, {0xa0?}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7622 +0x1b1 fp=0xc000044360 sp=0xc000044230 pc=0x7a7291 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*http2Transport).RoundTrip(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7571 Feb 16 20:53:03 znt go-librespot[1672]: net/http.http2noDialH2RoundTripper.RoundTrip({0xebc380?}, 0xc0001807e0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:10198 +0x1a fp=0xc0000443a0 sp=0xc000044360 pc=0x7b593a Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*Transport).roundTrip(0xebc380, 0xc0001806c0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/transport.go:553 +0x39c fp=0xc0000445c8 sp=0xc0000443a0 pc=0x7e053c Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*Transport).RoundTrip(0x42d7a5?, 0xb16380?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/roundtrip.go:17 +0x13 fp=0xc0000445e8 sp=0xc0000445c8 pc=0x7c5bf3 Feb 16 20:53:03 znt go-librespot[1672]: net/http.send(0xc0001806c0, {0xb16380, 0xebc380}, {0x101?, 0x15?, 0x0?}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/client.go:259 +0x5e4 fp=0xc0000447c8 sp=0xc0000445e8 pc=0x783304 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*Client).send(0xc00031be00, 0xc0001806c0, {0x4fa346?, 0x0?, 0x0?}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/client.go:180 +0x98 fp=0xc000044840 sp=0xc0000447c8 pc=0x782bb8 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*Client).do(0xc00031be00, 0xc0001806c0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/client.go:724 +0x8dc fp=0xc000044a30 sp=0xc000044840 pc=0x784edc Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*Client).Do(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/client.go:590 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/spclient.(*Spclient).request.func2() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/spclient/spclient.go:83 +0x199 fp=0xc000044ac0 sp=0xc000044a30 pc=0x83a319 Feb 16 20:53:03 znt go-librespot[1672]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0xc000044ca0?, {0xb19b98, 0xc00023c600}, 0x0, {0x0, 0x0?}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:88 +0x13d fp=0xc000044bc0 sp=0xc000044ac0 pc=0x82d23d Feb 16 20:53:03 znt go-librespot[1672]: github.com/cenkalti/backoff/v4.RetryNotifyWithData[...](...) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:54 Feb 16 20:53:03 znt go-librespot[1672]: github.com/cenkalti/backoff/v4.RetryWithData[...](0xc000343710?, {0xb19b98?, 0xc00023c600?}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:43 +0x2b fp=0xc000044c08 sp=0xc000044bc0 pc=0x82d0ab Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/spclient.(*Spclient).request(0xc0002c5b00, {0xa44ed0, 0x3}, {0xc00018a0a0?, 0x0?}, 0x0, 0xc000044f60, {0xc000340000, 0x19d, 0x19d}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/spclient/spclient.go:75 +0x387 fp=0xc000044d40 sp=0xc000044c08 pc=0x83a027 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/spclient.(*Spclient).PutConnectState(0xc0002c5b00, {0xc0001f72b0, 0xc8}, 0xc0003d1290) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/spclient/spclient.go:135 +0x30b fp=0xc000044fe0 sp=0xc000044d40 pc=0x83aceb Feb 16 20:53:03 znt go-librespot[1672]: main.(*AppPlayer).putConnectState(0xc0000ab500, 0x4) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/state.go:142 +0x27d fp=0xc000045020 sp=0xc000044fe0 pc=0x90f8dd Feb 16 20:53:03 znt go-librespot[1672]: main.(*AppPlayer).updateState(0xebb780?) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/state.go:107 +0x18 fp=0xc000045068 sp=0xc000045020 pc=0x90f5d8 Feb 16 20:53:03 znt go-librespot[1672]: main.(*AppPlayer).pause(0xc0000ab500) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/controls.go:370 +0x21e fp=0xc000045118 sp=0xc000045068 pc=0x90759e Feb 16 20:53:03 znt go-librespot[1672]: main.(*AppPlayer).handleApiRequest(0xc0000ab500, {{0xa4539b, 0x5}, {0x0, 0x0}, 0xc00023c180}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/player.go:338 +0x575 fp=0xc000045268 sp=0xc000045118 pc=0x90e035 Feb 16 20:53:03 znt go-librespot[1672]: main.(*AppPlayer).Run(0xc0000ab500, 0xc000330cc0) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/player.go:450 +0x69a fp=0xc000045fc0 sp=0xc000045268 pc=0x90eefa Feb 16 20:53:03 znt go-librespot[1672]: main.(*App).withAppPlayer.gowrap1() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:235 +0x25 fp=0xc000045fe0 sp=0xc000045fc0 pc=0x90a9a5 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000045fe8 sp=0xc000045fe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by main.(*App).withAppPlayer in goroutine 1 Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:235 +0x307 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 59 gp=0xc00035a1c0 m=nil [chan receive, 3 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0xc000347b00?, 0xc0001d2ba0?, 0x0?, 0x0?, 0xc00005cee8?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc00005ce98 sp=0xc00005ce78 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.chanrecv(0xc00008c420, 0xc00005cf98, 0x1) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:583 +0x3bf fp=0xc00005cf10 sp=0xc00005ce98 pc=0x4113ff Feb 16 20:53:03 znt go-librespot[1672]: runtime.chanrecv2(0x0?, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:447 +0x12 fp=0xc00005cf38 sp=0xc00005cf10 pc=0x411032 Feb 16 20:53:03 znt go-librespot[1672]: main.(*App).withAppPlayer.func1() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:245 +0x66 fp=0xc00005cfe0 sp=0xc00005cf38 pc=0x90a8e6 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00005cfe8 sp=0xc00005cfe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by main.(*App).withAppPlayer in goroutine 1 Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:242 +0x3a5 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 60 gp=0xc00035a380 m=nil [chan receive, 68 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc00005d678 sp=0xc00005d658 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.chanrecv(0xc00008c360, 0xc00005d7b8, 0x1) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:583 +0x3bf fp=0xc00005d6f0 sp=0xc00005d678 pc=0x4113ff Feb 16 20:53:03 znt go-librespot[1672]: runtime.chanrecv2(0x0?, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:447 +0x12 fp=0xc00005d718 sp=0xc00005d6f0 pc=0x411032 Feb 16 20:53:03 znt go-librespot[1672]: main.(*App).withAppPlayer.func2() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:261 +0x71 fp=0xc00005d7e0 sp=0xc00005d718 pc=0x90a591 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00005d7e8 sp=0xc00005d7e0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by main.(*App).withAppPlayer in goroutine 1 Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/main.go:258 +0x445 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 61 gp=0xc00035a540 m=nil [IO wait, 68 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0x41869b?, 0xc00004a7a8?, 0x0?, 0x0?, 0xc00005dca8?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc00024bc08 sp=0xc00024bbe8 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.netpollblock(0x7f6151665058?, 0x40e586?, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0xf7 fp=0xc00024bc40 sp=0xc00024bc08 pc=0x43e217 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.runtime_pollWait(0x7f61516b7c90, 0x72) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x85 fp=0xc00024bc60 sp=0xc00024bc40 pc=0x472185 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*pollDesc).wait(0x8?, 0x10?, 0x0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x27 fp=0xc00024bc88 sp=0xc00024bc60 pc=0x4e15c7 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*pollDesc).waitRead(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*FD).Accept(0xc0000ab100) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:611 +0x2ac fp=0xc00024bd30 sp=0xc00024bc88 pc=0x4e696c Feb 16 20:53:03 znt go-librespot[1672]: net.(*netFD).accept(0xc0000ab100) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_unix.go:172 +0x29 fp=0xc00024bde8 sp=0xc00024bd30 pc=0x65cfa9 Feb 16 20:53:03 znt go-librespot[1672]: net.(*TCPListener).accept(0xc00045d960) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/tcpsock_posix.go:159 +0x1e fp=0xc00024be10 sp=0xc00024bde8 pc=0x672efe Feb 16 20:53:03 znt go-librespot[1672]: net.(*TCPListener).Accept(0xc00045d960) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/tcpsock.go:327 +0x30 fp=0xc00024be40 sp=0xc00024be10 pc=0x6720f0 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*onceCloseListener).Accept(0xb1b050?) Feb 16 20:53:03 znt go-librespot[1672]: :1 +0x24 fp=0xc00024be58 sp=0xc00024be40 pc=0x7f6fe4 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*Server).Serve(0xc000173950, {0xb1a640, 0xc00045d960}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3255 +0x33e fp=0xc00024bf88 sp=0xc00024be58 pc=0x7d4f3e Feb 16 20:53:03 znt go-librespot[1672]: net/http.Serve(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2794 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/zeroconf.(*Zeroconf).Serve.func2() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/zeroconf/zeroconf.go:265 +0x85 fp=0xc00024bfe0 sp=0xc00024bf88 pc=0x8b9965 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00024bfe8 sp=0xc00024bfe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by go-librespot/zeroconf.(*Zeroconf).Serve in goroutine 1 Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/zeroconf/zeroconf.go:265 +0x165 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 63 gp=0xc00035a700 m=nil [select]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0xc0003e7dd0?, 0x2?, 0xd6?, 0xa2?, 0xc0003e7d7c?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc0003e7c20 sp=0xc0003e7c00 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.selectgo(0xc0003e7dd0, 0xc0003e7d78, 0x9547a0?, 0x0, 0xc00023c660?, 0x1) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0x725 fp=0xc0003e7d40 sp=0xc0003e7c20 pc=0x456825 Feb 16 20:53:03 znt go-librespot[1672]: github.com/cenkalti/backoff/v4.doRetryNotify[...](0xc0003e7e68?, {0xb19b98, 0xc00023c660}, 0x0, {0x0, 0x0?}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:112 +0x24f fp=0xc0003e7e30 sp=0xc0003e7d40 pc=0x81708f Feb 16 20:53:03 znt go-librespot[1672]: github.com/cenkalti/backoff/v4.RetryNotifyWithTimer(0xc0002ead00?, {0xb19b98?, 0xc00023c660?}, 0x991b00?, {0x0?, 0x0?}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:61 +0x5c fp=0xc0003e7e88 sp=0xc0003e7e30 pc=0x816b7c Feb 16 20:53:03 znt go-librespot[1672]: github.com/cenkalti/backoff/v4.RetryNotify(...) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:49 Feb 16 20:53:03 znt go-librespot[1672]: github.com/cenkalti/backoff/v4.Retry(...) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/github.com/cenkalti/backoff/v4@v4.2.1/retry.go:38 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/dealer.(*Dealer).recvLoop(0xc000233080) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:193 +0x471 fp=0xc0003e7fc8 sp=0xc0003e7e88 pc=0x84e431 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/dealer.(*Dealer).startReceiving.func1.gowrap1() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:99 +0x25 fp=0xc0003e7fe0 sp=0xc0003e7fc8 pc=0x84dc45 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0003e7fe8 sp=0xc0003e7fe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by go-librespot/dealer.(*Dealer).startReceiving.func1 in goroutine 58 Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/dealer/dealer.go:99 +0x56 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 73 gp=0xc00035ba40 m=nil [IO wait, 67 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0x7f6150dbb498?, 0x0?, 0x0?, 0x0?, 0xb?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc0000d32e8 sp=0xc0000d32c8 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.netpollblock(0x488a38?, 0x40e586?, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0xf7 fp=0xc0000d3320 sp=0xc0000d32e8 pc=0x43e217 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.runtime_pollWait(0x7f61516b74d0, 0x72) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x85 fp=0xc0000d3340 sp=0xc0000d3320 pc=0x472185 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*pollDesc).wait(0xc0003d2e80?, 0xc0003f2000?, 0x0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x27 fp=0xc0000d3368 sp=0xc0000d3340 pc=0x4e15c7 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*pollDesc).waitRead(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*FD).Read(0xc0003d2e80, {0xc0003f2000, 0x1000, 0x1000}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x27a fp=0xc0000d3400 sp=0xc0000d3368 pc=0x4e28ba Feb 16 20:53:03 znt go-librespot[1672]: net.(*netFD).Read(0xc0003d2e80, {0xc0003f2000?, 0x4516b7500?, 0x200000000?}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x25 fp=0xc0000d3448 sp=0xc0000d3400 pc=0x65afc5 Feb 16 20:53:03 znt go-librespot[1672]: net.(*conn).Read(0xc00004a078, {0xc0003f2000?, 0x455fd0?, 0x4454ae?}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x45 fp=0xc0000d3490 sp=0xc0000d3448 pc=0x669fa5 Feb 16 20:53:03 znt go-librespot[1672]: net.(*TCPConn).Read(0xc0000d35e0?, {0xc0003f2000?, 0xc0000d36f0?, 0x2?}) Feb 16 20:53:03 znt go-librespot[1672]: :1 +0x25 fp=0xc0000d34c0 sp=0xc0000d3490 pc=0x67b985 Feb 16 20:53:03 znt go-librespot[1672]: io.(*multiReader).Read(0xc0003acc60, {0xc0003f2000, 0x1000, 0x1000}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/multi.go:26 +0x93 fp=0xc0000d3508 sp=0xc0000d34c0 pc=0x4dcf33 Feb 16 20:53:03 znt go-librespot[1672]: bufio.(*Reader).fill(0xc00008ad80) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:110 +0x103 fp=0xc0000d3540 sp=0xc0000d3508 pc=0x531d03 Feb 16 20:53:03 znt go-librespot[1672]: bufio.(*Reader).ReadByte(0xc00008ad80) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:269 +0x27 fp=0xc0000d3560 sp=0xc0000d3540 pc=0x532427 Feb 16 20:53:03 znt go-librespot[1672]: nhooyr.io/websocket.readFrameHeader(0xc00008ad80, {0xc0002eb720, 0x8, 0x8}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/frame.go:54 +0x8b fp=0xc0000d35f0 sp=0xc0000d3560 pc=0x80f28b Feb 16 20:53:03 znt go-librespot[1672]: nhooyr.io/websocket.(*Conn).readFrameHeader(0xc0002eb6c0, {0xb1b050, 0xf646c0}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:188 +0xd9 fp=0xc0000d3730 sp=0xc0000d35f0 pc=0x810cd9 Feb 16 20:53:03 znt go-librespot[1672]: nhooyr.io/websocket.(*Conn).readLoop(0xc0002eb6c0, {0xb1b050, 0xf646c0}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:146 +0x65 fp=0xc0000d3890 sp=0xc0000d3730 pc=0x810645 Feb 16 20:53:03 znt go-librespot[1672]: nhooyr.io/websocket.(*Conn).reader(0xc0002eb6c0, {0xb1b050, 0xf646c0}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:315 +0x125 fp=0xc0000d3990 sp=0xc0000d3890 pc=0x811c45 Feb 16 20:53:03 znt go-librespot[1672]: nhooyr.io/websocket.(*Conn).Reader(...) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:30 Feb 16 20:53:03 znt go-librespot[1672]: nhooyr.io/websocket.(*Conn).Read(0xebb780?, {0xb1b050?, 0xf646c0?}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/read.go:36 +0x1e fp=0xc0000d39c0 sp=0xc0000d3990 pc=0x80ffbe Feb 16 20:53:03 znt go-librespot[1672]: main.(*ApiServer).serve.func14({0xb1a850, 0xc0001d0380}, 0xc000248b08?) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:450 +0x1c5 fp=0xc0000d3a70 sp=0xc0000d39c0 pc=0x902945 Feb 16 20:53:03 znt go-librespot[1672]: net/http.HandlerFunc.ServeHTTP(0xc000099930?, {0xb1a850?, 0xc0001d0380?}, 0xc000248aa0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2166 +0x29 fp=0xc0000d3a98 sp=0xc0000d3a70 pc=0x7d14e9 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*ServeMux).ServeHTTP(0xc000356350?, {0xb1a850, 0xc0001d0380}, 0xc0000d8480) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2683 +0x1ad fp=0xc0000d3ae8 sp=0xc0000d3a98 pc=0x7d33cd Feb 16 20:53:03 znt go-librespot[1672]: main.(*ApiServer).serve.(*ApiServer).allowOriginMiddleware.func15({0xb1a850?, 0xc0001d0380?}, 0xc000278840?) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:273 +0x9e fp=0xc0000d3b38 sp=0xc0000d3ae8 pc=0x90273e Feb 16 20:53:03 znt go-librespot[1672]: net/http.HandlerFunc.ServeHTTP(0x470d99?, {0xb1a850?, 0xc0001d0380?}, 0xc000248b68?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2166 +0x29 fp=0xc0000d3b60 sp=0xc0000d3b38 pc=0x7d14e9 Feb 16 20:53:03 znt go-librespot[1672]: net/http.serverHandler.ServeHTTP({0xc0003c1890?}, {0xb1a850?, 0xc0001d0380?}, 0x6?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3137 +0x8e fp=0xc0000d3b90 sp=0xc0000d3b60 pc=0x7d4b0e Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*conn).serve(0xc0003d1320, {0xb1b088, 0xc000150e10}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2039 +0x5e8 fp=0xc0000d3fb8 sp=0xc0000d3b90 pc=0x7cfec8 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*Server).Serve.gowrap3() Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3285 +0x28 fp=0xc0000d3fe0 sp=0xc0000d3fb8 pc=0x7d5328 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0000d3fe8 sp=0xc0000d3fe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by net/http.(*Server).Serve in goroutine 6 Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3285 +0x4b4 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 75 gp=0xc00035bc00 m=nil [select, 4 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0xc00024df38?, 0x5?, 0x60?, 0x12?, 0xc00024dee6?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc00024dd88 sp=0xc00024dd68 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.selectgo(0xc00024df38, 0xc00024dedc, 0x414ffd?, 0x0, 0x416bf0?, 0x1) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0x725 fp=0xc00024dea8 sp=0xc00024dd88 pc=0x456825 Feb 16 20:53:03 znt go-librespot[1672]: nhooyr.io/websocket.(*Conn).timeoutLoop(0xc0002eb6c0) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:153 +0x156 fp=0xc00024dfc8 sp=0xc00024dea8 pc=0x80bf96 Feb 16 20:53:03 znt go-librespot[1672]: nhooyr.io/websocket.newConn.gowrap1() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x25 fp=0xc00024dfe0 sp=0xc00024dfc8 pc=0x80bb05 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00024dfe8 sp=0xc00024dfe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by nhooyr.io/websocket.newConn in goroutine 73 Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/go/pkg/mod/nhooyr.io/websocket@v1.8.7/conn_notjs.go:114 +0x4c5 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 83 gp=0xc0000fddc0 m=nil [select, 4 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0xc0003e9c18?, 0x3?, 0xe0?, 0x99?, 0xc0003e9b1e?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc0003e99b8 sp=0xc0003e9998 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.selectgo(0xc0003e9c18, 0xc0003e9b18, 0x1d?, 0x0, 0x948d20?, 0x1) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0x725 fp=0xc0003e9ad8 sp=0xc0003e99b8 pc=0x456825 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/audio.(*KeyProvider).recvLoop(0xc000342fc0) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/audio/provider.go:52 +0x185 fp=0xc0003e9fc8 sp=0xc0003e9ad8 pc=0x82c485 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/audio.(*KeyProvider).startReceiving.func1.gowrap1() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/audio/provider.go:42 +0x25 fp=0xc0003e9fe0 sp=0xc0003e9fc8 pc=0x82c2c5 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0003e9fe8 sp=0xc0003e9fe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by go-librespot/audio.(*KeyProvider).startReceiving.func1 in goroutine 58 Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/audio/provider.go:42 +0x56 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 174013 gp=0xc0001f4e00 m=nil [select, 3 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0xc000c16f10?, 0x6?, 0x0?, 0x0?, 0xc000c16dcc?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc000c16c48 sp=0xc000c16c28 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.selectgo(0xc000c16f10, 0xc000c16dc0, 0xa45a24?, 0x0, 0x0?, 0x1) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/select.go:327 +0x725 fp=0xc000c16d68 sp=0xc000c16c48 pc=0x456825 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*http2clientStream).writeRequest(0xc00019f200, 0xc0001807e0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:8522 +0xacc fp=0xc000c16f98 sp=0xc000c16d68 pc=0x7ac2ac Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*http2clientStream).doRequest(0xc00019f200, 0xc000372da0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:8384 +0x18 fp=0xc000c16fc0 sp=0xc000c16f98 pc=0x7ab798 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*http2ClientConn).RoundTrip.gowrap1() Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:8290 +0x25 fp=0xc000c16fe0 sp=0xc000c16fc0 pc=0x7ab745 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000c16fe8 sp=0xc000c16fe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by net/http.(*http2ClientConn).RoundTrip in goroutine 58 Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:8290 +0x2ed Feb 16 20:53:03 znt go-librespot[1672]: goroutine 169610 gp=0xc0001f5180 m=nil [IO wait, 4 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0x5d4c2e10924db4d7?, 0x4e68da0bc428bcf2?, 0xd7?, 0xb4?, 0xb?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc0004a96d8 sp=0xc0004a96b8 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.netpollblock(0x488a38?, 0x40e586?, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0xf7 fp=0xc0004a9710 sp=0xc0004a96d8 pc=0x43e217 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.runtime_pollWait(0x7f61516b70f0, 0x72) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x85 fp=0xc0004a9730 sp=0xc0004a9710 pc=0x472185 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*pollDesc).wait(0xc00020d380?, 0xc000334000?, 0x0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x27 fp=0xc0004a9758 sp=0xc0004a9730 pc=0x4e15c7 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*pollDesc).waitRead(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*FD).Read(0xc00020d380, {0xc000334000, 0x1000, 0x1000}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x27a fp=0xc0004a97f0 sp=0xc0004a9758 pc=0x4e28ba Feb 16 20:53:03 znt go-librespot[1672]: net.(*netFD).Read(0xc00020d380, {0xc000334000?, 0x7f61999501a8?, 0xc000012a68?}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x25 fp=0xc0004a9838 sp=0xc0004a97f0 pc=0x65afc5 Feb 16 20:53:03 znt go-librespot[1672]: net.(*conn).Read(0xc0001c40d8, {0xc000334000?, 0xc0004a9918?, 0x41869b?}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x45 fp=0xc0004a9880 sp=0xc0004a9838 pc=0x669fa5 Feb 16 20:53:03 znt go-librespot[1672]: net.(*TCPConn).Read(0xc000178480?, {0xc000334000?, 0x5?, 0x240?}) Feb 16 20:53:03 znt go-librespot[1672]: :1 +0x25 fp=0xc0004a98b0 sp=0xc0004a9880 pc=0x67b985 Feb 16 20:53:03 znt go-librespot[1672]: crypto/tls.(*atLeastReader).Read(0xc000012a68, {0xc000334000?, 0x0?, 0xc000012a68?}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:806 +0x3b fp=0xc0004a98f8 sp=0xc0004a98b0 pc=0x724afb Feb 16 20:53:03 znt go-librespot[1672]: bytes.(*Buffer).ReadFrom(0xc0002382b0, {0xb17ee0, 0xc000012a68}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/bytes/buffer.go:211 +0x98 fp=0xc0004a9950 sp=0xc0004a98f8 pc=0x50e478 Feb 16 20:53:03 znt go-librespot[1672]: crypto/tls.(*Conn).readFromUntil(0xc000238008, {0xb15e00, 0xc0001c40d8}, 0xc0004a9960?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:828 +0xde fp=0xc0004a9988 sp=0xc0004a9950 pc=0x724cde Feb 16 20:53:03 znt go-librespot[1672]: crypto/tls.(*Conn).readRecordOrCCS(0xc000238008, 0x0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:626 +0x3cf fp=0xc0004a9c08 sp=0xc0004a9988 pc=0x721def Feb 16 20:53:03 znt go-librespot[1672]: crypto/tls.(*Conn).readRecord(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:588 Feb 16 20:53:03 znt go-librespot[1672]: crypto/tls.(*Conn).Read(0xc000238008, {0xc00016c000, 0x1000, 0x11?}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/crypto/tls/conn.go:1370 +0x156 fp=0xc0004a9c78 sp=0xc0004a9c08 pc=0x728696 Feb 16 20:53:03 znt go-librespot[1672]: bufio.(*Reader).Read(0xc00031d320, {0xc0001d02e0, 0x9, 0x7f5c4e?}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/bufio/bufio.go:241 +0x197 fp=0xc0004a9cb0 sp=0xc0004a9c78 pc=0x532237 Feb 16 20:53:03 znt go-librespot[1672]: io.ReadAtLeast({0xb16160, 0xc00031d320}, {0xc0001d02e0, 0x9, 0x9}, 0x9) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:335 +0x90 fp=0xc0004a9cf8 sp=0xc0004a9cb0 pc=0x4dc050 Feb 16 20:53:03 znt go-librespot[1672]: io.ReadFull(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/io/io.go:354 Feb 16 20:53:03 znt go-librespot[1672]: net/http.http2readFrameHeader({0xc0001d02e0, 0x9, 0x7b50d2?}, {0xb16160?, 0xc00031d320?}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1638 +0x65 fp=0xc0004a9d48 sp=0xc0004a9cf8 pc=0x78d625 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*http2Framer).ReadFrame(0xc0001d02a0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:1902 +0x85 fp=0xc0004a9df0 sp=0xc0004a9d48 pc=0x78dd65 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*http2clientConnReadLoop).run(0xc0004a9fa8) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9334 +0x12c fp=0xc0004a9f60 sp=0xc0004a9df0 pc=0x7b0a0c Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*http2ClientConn).readLoop(0xc00019f680) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:9229 +0x65 fp=0xc0004a9fc8 sp=0xc0004a9f60 pc=0x7aff85 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*http2Transport).newClientConn.gowrap1() Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0x25 fp=0xc0004a9fe0 sp=0xc0004a9fc8 pc=0x7a8f25 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0004a9fe8 sp=0xc0004a9fe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by net/http.(*http2Transport).newClientConn in goroutine 169609 Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/h2_bundle.go:7879 +0xca6 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 174008 gp=0xc00029e1c0 m=nil [chan receive, 3 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0x354008?, 0xc000347b00?, 0x20?, 0x0?, 0xc000c178d0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc000c17880 sp=0xc000c17860 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.chanrecv(0xc00023c180, 0xc000c179f0, 0x1) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:583 +0x3bf fp=0xc000c178f8 sp=0xc000c17880 pc=0x4113ff Feb 16 20:53:03 znt go-librespot[1672]: runtime.chanrecv1(0x4?, 0x1?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/chan.go:442 +0x12 fp=0xc000c17920 sp=0xc000c178f8 pc=0x411012 Feb 16 20:53:03 znt go-librespot[1672]: main.(*ApiServer).handleRequest(0xc00008a480, {{0xa4539b, 0x5}, {0x0, 0x0}, 0xc00023c180}, {0xb1a850, 0xc0001d00e0}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:253 +0xc5 fp=0xc000c17a20 sp=0xc000c17920 pc=0x901e05 Feb 16 20:53:03 znt go-librespot[1672]: main.(*ApiServer).serve.func5({0xb1a850?, 0xc0001d00e0?}, 0xc000c17b08?) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:319 +0x77 fp=0xc000c17a70 sp=0xc000c17a20 pc=0x903a77 Feb 16 20:53:03 znt go-librespot[1672]: net/http.HandlerFunc.ServeHTTP(0xc000099930?, {0xb1a850?, 0xc0001d00e0?}, 0xc000c17aa0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2166 +0x29 fp=0xc000c17a98 sp=0xc000c17a70 pc=0x7d14e9 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*ServeMux).ServeHTTP(0xc000af85d0?, {0xb1a850, 0xc0001d00e0}, 0xc000180480) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2683 +0x1ad fp=0xc000c17ae8 sp=0xc000c17a98 pc=0x7d33cd Feb 16 20:53:03 znt go-librespot[1672]: main.(*ApiServer).serve.(*ApiServer).allowOriginMiddleware.func15({0xb1a850?, 0xc0001d00e0?}, 0xc000278000?) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/cmd/daemon/api_server.go:273 +0x9e fp=0xc000c17b38 sp=0xc000c17ae8 pc=0x90273e Feb 16 20:53:03 znt go-librespot[1672]: net/http.HandlerFunc.ServeHTTP(0x470d99?, {0xb1a850?, 0xc0001d00e0?}, 0xc000c17b68?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2166 +0x29 fp=0xc000c17b60 sp=0xc000c17b38 pc=0x7d14e9 Feb 16 20:53:03 znt go-librespot[1672]: net/http.serverHandler.ServeHTTP({0xc000342bd0?}, {0xb1a850?, 0xc0001d00e0?}, 0x6?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3137 +0x8e fp=0xc000c17b90 sp=0xc000c17b60 pc=0x7d4b0e Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*conn).serve(0xc0003d10e0, {0xb1b088, 0xc000150e10}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:2039 +0x5e8 fp=0xc000c17fb8 sp=0xc000c17b90 pc=0x7cfec8 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*Server).Serve.gowrap3() Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3285 +0x28 fp=0xc000c17fe0 sp=0xc000c17fb8 pc=0x7d5328 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000c17fe8 sp=0xc000c17fe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by net/http.(*Server).Serve in goroutine 6 Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:3285 +0x4b4 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 169631 gp=0xc00033d500 m=nil [sync.Cond.Wait, 3 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0x835d4a?, 0xc000015f54?, 0xf0?, 0x56?, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc0004456b8 sp=0xc000445698 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.goparkunlock(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 Feb 16 20:53:03 znt go-librespot[1672]: sync.runtime_notifyListWait(0xc000379a10, 0x2) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/sema.go:569 +0x159 fp=0xc000445708 sp=0xc0004456b8 pc=0x473cb9 Feb 16 20:53:03 znt go-librespot[1672]: sync.(*Cond).Wait(0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/sync/cond.go:70 +0x85 fp=0xc000445748 sp=0xc000445708 pc=0x480cc5 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/output.(*output).writeLoop(0xc000174d00) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:292 +0x18e fp=0xc0004457a8 sp=0xc000445748 pc=0x832e6e Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/output.newOutput.func3() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:98 +0x1c fp=0xc0004457e0 sp=0xc0004457a8 pc=0x830b5c Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc0004457e8 sp=0xc0004457e0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by go-librespot/output.newOutput in goroutine 56 Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:97 +0x445 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 169630 gp=0xc00028f340 m=nil [sync.Cond.Wait, 3 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0x83e089?, 0x0?, 0x80?, 0xee?, 0xc00024eeb8?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc00024ee58 sp=0xc00024ee38 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.goparkunlock(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:408 Feb 16 20:53:03 znt go-librespot[1672]: sync.runtime_notifyListWait(0xc000379ad0, 0x756) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/sema.go:569 +0x159 fp=0xc00024eea8 sp=0xc00024ee58 pc=0x473cb9 Feb 16 20:53:03 znt go-librespot[1672]: sync.(*Cond).Wait(0xc000667800?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/sync/cond.go:70 +0x85 fp=0xc00024eee8 sp=0xc00024eea8 pc=0x480cc5 Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/output.(*RingBuffer[...]).PutWait(0xc000667800, {0xc000667800?, 0x5be, 0x5be}) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/output/ring_buffer.go:50 +0xaf fp=0xc00024ef40 sp=0xc00024eee8 pc=0x83614f Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/output.(*output).readLoop(0xc000174d00) Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:252 +0xac fp=0xc00024efa8 sp=0xc00024ef40 pc=0x832bcc Feb 16 20:53:03 znt go-librespot[1672]: go-librespot/output.newOutput.func2() Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:93 +0x1c fp=0xc00024efe0 sp=0xc00024efa8 pc=0x830bbc Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc00024efe8 sp=0xc00024efe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by go-librespot/output.newOutput in goroutine 56 Feb 16 20:53:03 znt go-librespot[1672]: /home/runner/work/go-librespot/go-librespot/output/driver_unix.go:92 +0x405 Feb 16 20:53:03 znt go-librespot[1672]: goroutine 174012 gp=0xc000168540 m=nil [IO wait, 3 minutes]: Feb 16 20:53:03 znt go-librespot[1672]: runtime.gopark(0x0?, 0x0?, 0x0?, 0x0?, 0xb?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/proc.go:402 +0xce fp=0xc000c25da8 sp=0xc000c25d88 pc=0x4454ae Feb 16 20:53:03 znt go-librespot[1672]: runtime.netpollblock(0x488a38?, 0x40e586?, 0x0?) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:573 +0xf7 fp=0xc000c25de0 sp=0xc000c25da8 pc=0x43e217 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.runtime_pollWait(0x7f61516b77b8, 0x72) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/netpoll.go:345 +0x85 fp=0xc000c25e00 sp=0xc000c25de0 pc=0x472185 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*pollDesc).wait(0xc00020c500?, 0xc000342be1?, 0x0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:84 +0x27 fp=0xc000c25e28 sp=0xc000c25e00 pc=0x4e15c7 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*pollDesc).waitRead(...) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_poll_runtime.go:89 Feb 16 20:53:03 znt go-librespot[1672]: internal/poll.(*FD).Read(0xc00020c500, {0xc000342be1, 0x1, 0x1}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/internal/poll/fd_unix.go:164 +0x27a fp=0xc000c25ec0 sp=0xc000c25e28 pc=0x4e28ba Feb 16 20:53:03 znt go-librespot[1672]: net.(*netFD).Read(0xc00020c500, {0xc000342be1?, 0x1a7800?, 0xc000379900?}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/fd_posix.go:55 +0x25 fp=0xc000c25f08 sp=0xc000c25ec0 pc=0x65afc5 Feb 16 20:53:03 znt go-librespot[1672]: net.(*conn).Read(0xc0002d0ff8, {0xc000342be1?, 0x0?, 0x98a840?}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/net.go:179 +0x45 fp=0xc000c25f50 sp=0xc000c25f08 pc=0x669fa5 Feb 16 20:53:03 znt go-librespot[1672]: net.(*TCPConn).Read(0xc0001cad70?, {0xc000342be1?, 0x0?, 0xc000c25fb8?}) Feb 16 20:53:03 znt go-librespot[1672]: :1 +0x25 fp=0xc000c25f80 sp=0xc000c25f50 pc=0x67b985 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*connReader).backgroundRead(0xc000342bd0) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:681 +0x37 fp=0xc000c25fc8 sp=0xc000c25f80 pc=0x7c9e37 Feb 16 20:53:03 znt go-librespot[1672]: net/http.(*connReader).startBackgroundRead.gowrap2() Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:677 +0x25 fp=0xc000c25fe0 sp=0xc000c25fc8 pc=0x7c9d65 Feb 16 20:53:03 znt go-librespot[1672]: runtime.goexit({}) Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/runtime/asm_amd64.s:1695 +0x1 fp=0xc000c25fe8 sp=0xc000c25fe0 pc=0x477401 Feb 16 20:53:03 znt go-librespot[1672]: created by net/http.(*connReader).startBackgroundRead in goroutine 174008 Feb 16 20:53:03 znt go-librespot[1672]: /opt/hostedtoolcache/go/1.22.2/x64/src/net/http/server.go:677 +0xba Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:0iDHfRNAxWdEJSUZ23l9iF in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:0iDHfRNAxWdEJSUZ23l9iF Feb 16 20:53:03 znt volumio[1183]: error: Failed to send command to Spotify local API: /player/pause: Error: socket hang up Feb 16 20:53:03 znt go-librespot[1672]: Aborted Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:0iDHfRNAxWdEJSUZ23l9iF from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Connection to go-librespot Websocket closed Feb 16 20:53:03 znt systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=134/n/a Feb 16 20:53:03 znt systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:7nqmjUf6rmamJt02nZa4a4 in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:7nqmjUf6rmamJt02nZa4a4 Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:7nqmjUf6rmamJt02nZa4a4 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:3KbYGEZFEj6OYZ8KI2lMQy in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:3KbYGEZFEj6OYZ8KI2lMQy Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:3KbYGEZFEj6OYZ8KI2lMQy from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:4NwY0J5QurkzovHm1VEvDy in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:4NwY0J5QurkzovHm1VEvDy Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:4NwY0J5QurkzovHm1VEvDy from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:1pBI0CumuXGLAsvmBf3HSu in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:1pBI0CumuXGLAsvmBf3HSu Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:1pBI0CumuXGLAsvmBf3HSu from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:1aat6Gzqaxc3AEJVxTJxjc in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:1aat6Gzqaxc3AEJVxTJxjc Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:1aat6Gzqaxc3AEJVxTJxjc from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:0wH3V4K9UPjUOGRcYpCQEj in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:0wH3V4K9UPjUOGRcYpCQEj Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:0wH3V4K9UPjUOGRcYpCQEj from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:2fo3itviTrZPgfsygMuQMj in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:2fo3itviTrZPgfsygMuQMj Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:2fo3itviTrZPgfsygMuQMj from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:1jFyGu7sdxuUgeQ1Skq0cc in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:1jFyGu7sdxuUgeQ1Skq0cc Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:1jFyGu7sdxuUgeQ1Skq0cc from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:5zjzdH9KGAxB75Pyu3j0tc in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:5zjzdH9KGAxB75Pyu3j0tc Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:5zjzdH9KGAxB75Pyu3j0tc from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:6riq2aRoEYbdrEt80RLqK9 in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:6riq2aRoEYbdrEt80RLqK9 Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:6riq2aRoEYbdrEt80RLqK9 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:6hpAbOImGVRTrrwRDmZOTY in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:6hpAbOImGVRTrrwRDmZOTY Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:6hpAbOImGVRTrrwRDmZOTY from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:35kQ9ZpF377PSJs8Bp9gtn in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:35kQ9ZpF377PSJs8Bp9gtn Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:35kQ9ZpF377PSJs8Bp9gtn from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:72YAQ49UBBDMEQxE3KXxBY in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:72YAQ49UBBDMEQxE3KXxBY Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:72YAQ49UBBDMEQxE3KXxBY from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:7FCXRr3TCDiNn79SrUaIK2 in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:7FCXRr3TCDiNn79SrUaIK2 Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:7FCXRr3TCDiNn79SrUaIK2 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:4Kw9KysyP6y6YGoEffYT3S in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:4Kw9KysyP6y6YGoEffYT3S Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:4Kw9KysyP6y6YGoEffYT3S from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri upnp/folder/http://192.168.188.21:50001/ContentDirectory/control@22$483 in service upnp_browser Feb 16 20:53:03 znt volumio[1183]: error: connect ENETUNREACH 192.168.188.21:50001 - Local (0.0.0.0:0) {"errno":-101,"code":"ENETUNREACH","syscall":"connect","address":"192.168.188.21","port":50001} Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:0ejJSN0yCHGkyC4ZHgWzpb in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:0ejJSN0yCHGkyC4ZHgWzpb Feb 16 20:53:03 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:0ejJSN0yCHGkyC4ZHgWzpb from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:03 znt volumio[1183]: info: Exploding uri spotify:track:6JgtkXohSi6uBYwqdy89DP in service spop Feb 16 20:53:03 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:6JgtkXohSi6uBYwqdy89DP Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:6JgtkXohSi6uBYwqdy89DP from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:6aeWtey0Q1ZLpjQny5cyU6 in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:6aeWtey0Q1ZLpjQny5cyU6 Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:6aeWtey0Q1ZLpjQny5cyU6 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:0cAdo09bcV93qw2UzaiMo4 in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:0cAdo09bcV93qw2UzaiMo4 Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:0cAdo09bcV93qw2UzaiMo4 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:126SHpoZRqPs8CX6wWLo46 in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:126SHpoZRqPs8CX6wWLo46 Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:126SHpoZRqPs8CX6wWLo46 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:3yf0NDUue2VqsWpxDYLUPc in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:3yf0NDUue2VqsWpxDYLUPc Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:3yf0NDUue2VqsWpxDYLUPc from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:1wJxSYpxvufStONDfPfEMp in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:1wJxSYpxvufStONDfPfEMp Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:1wJxSYpxvufStONDfPfEMp from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:6AIaPepPICSN9eWlpO7tEA in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:6AIaPepPICSN9eWlpO7tEA Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:6AIaPepPICSN9eWlpO7tEA from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:4rkR35wElxIvUDmD2RbrOz in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:4rkR35wElxIvUDmD2RbrOz Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:4rkR35wElxIvUDmD2RbrOz from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:1Hrd97tIWFukJzDy2ZKeLn in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:1Hrd97tIWFukJzDy2ZKeLn Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:1Hrd97tIWFukJzDy2ZKeLn from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:3WPB2SFZen5FyVYMj8cqf9 in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:3WPB2SFZen5FyVYMj8cqf9 Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:3WPB2SFZen5FyVYMj8cqf9 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:0Se6Ly56UJ9TUW9W1bTFbV in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:0Se6Ly56UJ9TUW9W1bTFbV Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:0Se6Ly56UJ9TUW9W1bTFbV from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:7FFjAt14A3Rl4ApoqvrBec in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:7FFjAt14A3Rl4ApoqvrBec Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:7FFjAt14A3Rl4ApoqvrBec from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:5u9xarAztF6fYkWxnlv1GC in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:5u9xarAztF6fYkWxnlv1GC Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:5u9xarAztF6fYkWxnlv1GC from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:7a6LCZEuPRjP91PKkCYRlS in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:7a6LCZEuPRjP91PKkCYRlS Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:7a6LCZEuPRjP91PKkCYRlS from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:4y6xQW6De7HXu9X8TGYHwx in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:4y6xQW6De7HXu9X8TGYHwx Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:4y6xQW6De7HXu9X8TGYHwx from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:0VXqMR0b6aEvdW3novJ8bw in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:0VXqMR0b6aEvdW3novJ8bw Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:0VXqMR0b6aEvdW3novJ8bw from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:5j9M4piQrZhUDg0aOQ1EyN in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:5j9M4piQrZhUDg0aOQ1EyN Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:5j9M4piQrZhUDg0aOQ1EyN from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:4FEojeJH30lXGFrU0sAlpo in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:4FEojeJH30lXGFrU0sAlpo Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:4FEojeJH30lXGFrU0sAlpo from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:2ZGKkSXDEZ1i8Zmzmkn9px in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:2ZGKkSXDEZ1i8Zmzmkn9px Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:2ZGKkSXDEZ1i8Zmzmkn9px from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:4e0VDn9a6LFT35u2H8v9uo in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:4e0VDn9a6LFT35u2H8v9uo Feb 16 20:53:04 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:4e0VDn9a6LFT35u2H8v9uo from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:04 znt volumio[1183]: info: Exploding uri spotify:track:61me61UGavnApjgG2MUIKs in service spop Feb 16 20:53:04 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:61me61UGavnApjgG2MUIKs Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:61me61UGavnApjgG2MUIKs from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:7lOaeWlI5YaA6yLignuxQP in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:7lOaeWlI5YaA6yLignuxQP Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:7lOaeWlI5YaA6yLignuxQP from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:2JY4AMYnEPt49f7AyyxI9i in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:2JY4AMYnEPt49f7AyyxI9i Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:2JY4AMYnEPt49f7AyyxI9i from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:5Ks0fikFSkpCILRYdlCRUD in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:5Ks0fikFSkpCILRYdlCRUD Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:5Ks0fikFSkpCILRYdlCRUD from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:3VygbLR70zCdxanglfcb30 in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:3VygbLR70zCdxanglfcb30 Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:3VygbLR70zCdxanglfcb30 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:168yC2HtY8gBosw9n17cWU in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:168yC2HtY8gBosw9n17cWU Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:168yC2HtY8gBosw9n17cWU from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:44E9lhFeSXkAd0kWqfnDn1 in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:44E9lhFeSXkAd0kWqfnDn1 Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:44E9lhFeSXkAd0kWqfnDn1 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:5C90brGfAc9tLXCCJs9DLt in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:5C90brGfAc9tLXCCJs9DLt Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:5C90brGfAc9tLXCCJs9DLt from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:6A23a94f2xpbu3Un9L9o5T in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:6A23a94f2xpbu3Un9L9o5T Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:6A23a94f2xpbu3Un9L9o5T from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:7cyI0tN3fT3qlgyt3SDw0k in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:7cyI0tN3fT3qlgyt3SDw0k Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:7cyI0tN3fT3qlgyt3SDw0k from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:5583e6W6aXpsV5veZxcfvE in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:5583e6W6aXpsV5veZxcfvE Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:5583e6W6aXpsV5veZxcfvE from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:6SkHKuXMa7Z8OqOd4F11aA in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:6SkHKuXMa7Z8OqOd4F11aA Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:6SkHKuXMa7Z8OqOd4F11aA from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:4Wh9I9F0KA07GsXwWdC9p9 in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:4Wh9I9F0KA07GsXwWdC9p9 Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:4Wh9I9F0KA07GsXwWdC9p9 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:3l3cOYICR4o1mObp2nS19X in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:3l3cOYICR4o1mObp2nS19X Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:3l3cOYICR4o1mObp2nS19X from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:4t9dDzKD5gbjcOwWse2Up1 in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:4t9dDzKD5gbjcOwWse2Up1 Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:4t9dDzKD5gbjcOwWse2Up1 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:1Sv8l0pZa6r8TUSQCGM8iU in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:1Sv8l0pZa6r8TUSQCGM8iU Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:1Sv8l0pZa6r8TUSQCGM8iU from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:4CqhUMO6iyJo1BClPXzJq1 in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:4CqhUMO6iyJo1BClPXzJq1 Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:4CqhUMO6iyJo1BClPXzJq1 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:4JXtnw6Mu4d2DGmPwYqa60 in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:4JXtnw6Mu4d2DGmPwYqa60 Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:4JXtnw6Mu4d2DGmPwYqa60 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:7D6FRgePpcrzJSlqgFqJpX in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:7D6FRgePpcrzJSlqgFqJpX Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:7D6FRgePpcrzJSlqgFqJpX from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:05 znt volumio[1183]: info: Exploding uri spotify:track:0oxyw2edKA7JJbbeFh84h3 in service spop Feb 16 20:53:05 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:0oxyw2edKA7JJbbeFh84h3 Feb 16 20:53:05 znt volumio[1183]: error: Commandrouter: Cannot explode uri spotify:track:0oxyw2edKA7JJbbeFh84h3 from service spop: Error: Spotify API method getTrack failed: Error: getaddrinfo EBUSY api.spotify.com Feb 16 20:53:06 znt volumio[1183]: info: Initializing connection to go-librespot Websocket Feb 16 20:53:06 znt volumio[1183]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:53:06 znt systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:53:06 znt systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 16 20:53:06 znt systemd[1]: Stopped go-librespot Daemon. Feb 16 20:53:06 znt go-librespot[13710]: Librespot-go daemon starting... Feb 16 20:53:06 znt systemd[1]: Started go-librespot Daemon. Feb 16 20:53:06 znt go-librespot[13710]: time="2025-02-16T20:53:06Z" level=info msg="generated new device id: 12689ea964ccc04adca8a8970031c17f60592fb4" Feb 16 20:53:06 znt go-librespot[13710]: time="2025-02-16T20:53:06Z" level=debug msg="stored credentials found for 316v3nxg7xb6isf4fs43ze7xzx6a" Feb 16 20:53:06 znt go-librespot[13710]: time="2025-02-16T20:53:06Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 16 20:53:06 znt systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:53:06 znt systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:53:09 znt volumio[1183]: info: Initializing connection to go-librespot Websocket Feb 16 20:53:09 znt volumio[1183]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:53:09 znt systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:53:09 znt systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 16 20:53:09 znt systemd[1]: Stopped go-librespot Daemon. Feb 16 20:53:09 znt systemd[1]: Started go-librespot Daemon. Feb 16 20:53:09 znt go-librespot[13718]: Librespot-go daemon starting... Feb 16 20:53:09 znt go-librespot[13718]: time="2025-02-16T20:53:09Z" level=info msg="generated new device id: 814c24f71738c1f04f441e0463c1ad6fea53803a" Feb 16 20:53:09 znt go-librespot[13718]: time="2025-02-16T20:53:09Z" level=debug msg="stored credentials found for 316v3nxg7xb6isf4fs43ze7xzx6a" Feb 16 20:53:09 znt go-librespot[13718]: time="2025-02-16T20:53:09Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 16 20:53:09 znt systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:53:09 znt systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:53:12 znt volumio[1183]: info: Initializing connection to go-librespot Websocket Feb 16 20:53:12 znt volumio[1183]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:53:12 znt systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:53:12 znt systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 16 20:53:12 znt systemd[1]: Stopped go-librespot Daemon. Feb 16 20:53:12 znt systemd[1]: Started go-librespot Daemon. Feb 16 20:53:12 znt go-librespot[13723]: Librespot-go daemon starting... Feb 16 20:53:12 znt go-librespot[13723]: time="2025-02-16T20:53:12Z" level=info msg="generated new device id: e5d1f53581d3a137b325fa7e48bd3ea69fab7aac" Feb 16 20:53:12 znt go-librespot[13723]: time="2025-02-16T20:53:12Z" level=debug msg="stored credentials found for 316v3nxg7xb6isf4fs43ze7xzx6a" Feb 16 20:53:12 znt go-librespot[13723]: time="2025-02-16T20:53:12Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 16 20:53:12 znt systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:53:12 znt systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:53:15 znt volumio[1183]: info: Initializing connection to go-librespot Websocket Feb 16 20:53:15 znt volumio[1183]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:53:15 znt systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:53:15 znt systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 16 20:53:15 znt systemd[1]: Stopped go-librespot Daemon. Feb 16 20:53:15 znt systemd[1]: Started go-librespot Daemon. Feb 16 20:53:15 znt go-librespot[13742]: Librespot-go daemon starting... Feb 16 20:53:15 znt go-librespot[13742]: time="2025-02-16T20:53:15Z" level=info msg="generated new device id: 75a5f4cac8e0dcb66198e50fe9f9cbc032bf215e" Feb 16 20:53:15 znt go-librespot[13742]: time="2025-02-16T20:53:15Z" level=debug msg="stored credentials found for 316v3nxg7xb6isf4fs43ze7xzx6a" Feb 16 20:53:15 znt go-librespot[13742]: time="2025-02-16T20:53:15Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 16 20:53:15 znt systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:53:15 znt systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:53:16 znt wpa_supplicant[1077]: wlan0: SME: Trying to authenticate with 4c:5e:0c:b5:06:d1 (SSID='MikroTik_2.4' freq=2412 MHz) Feb 16 20:53:16 znt kernel: wlan0: authenticate with 4c:5e:0c:b5:06:d1 Feb 16 20:53:16 znt kernel: wlan0: 80 MHz not supported, disabling VHT Feb 16 20:53:16 znt kernel: wlan0: send auth to 4c:5e:0c:b5:06:d1 (try 1/3) Feb 16 20:53:16 znt kernel: wlan0: authenticated Feb 16 20:53:16 znt wpa_supplicant[1077]: wlan0: Trying to associate with 4c:5e:0c:b5:06:d1 (SSID='MikroTik_2.4' freq=2412 MHz) Feb 16 20:53:16 znt kernel: wlan0: associate with 4c:5e:0c:b5:06:d1 (try 1/3) Feb 16 20:53:16 znt kernel: wlan0: RX AssocResp from 4c:5e:0c:b5:06:d1 (capab=0x401 status=0 aid=1) Feb 16 20:53:16 znt wpa_supplicant[1077]: wlan0: Associated with 4c:5e:0c:b5:06:d1 Feb 16 20:53:16 znt wpa_supplicant[1077]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Feb 16 20:53:16 znt kernel: wlan0: associated Feb 16 20:53:16 znt wpa_supplicant[1077]: wlan0: WPA: Key negotiation completed with 4c:5e:0c:b5:06:d1 [PTK=CCMP GTK=CCMP] Feb 16 20:53:16 znt wpa_supplicant[1077]: wlan0: CTRL-EVENT-CONNECTED - Connection to 4c:5e:0c:b5:06:d1 completed [id=0 id_str=] Feb 16 20:53:16 znt dhcpcd[923]: wlan0: carrier acquired Feb 16 20:53:16 znt dhcpcd[923]: wlan0: IAID b6:cc:13:39 Feb 16 20:53:16 znt dhcpcd[923]: wlan0: soliciting an IPv6 router Feb 16 20:53:16 znt dhcpcd[923]: wlan0: rebinding lease of 192.168.188.55 Feb 16 20:53:16 znt dhcpcd[923]: wlan0: probing address 192.168.188.55/24 Feb 16 20:53:18 znt volumio[1183]: info: Initializing connection to go-librespot Websocket Feb 16 20:53:18 znt volumio[1183]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:53:19 znt systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:53:19 znt systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 16 20:53:19 znt systemd[1]: Stopped go-librespot Daemon. Feb 16 20:53:19 znt systemd[1]: Started go-librespot Daemon. Feb 16 20:53:19 znt go-librespot[13751]: Librespot-go daemon starting... Feb 16 20:53:19 znt go-librespot[13751]: time="2025-02-16T20:53:19Z" level=info msg="generated new device id: 33107931f89caa75660dd4b49dbbbca9ebccf390" Feb 16 20:53:19 znt go-librespot[13751]: time="2025-02-16T20:53:19Z" level=debug msg="stored credentials found for 316v3nxg7xb6isf4fs43ze7xzx6a" Feb 16 20:53:19 znt go-librespot[13751]: time="2025-02-16T20:53:19Z" level=fatal msg="failed running with username and spotify token" error="failed getting endpoints from resolver: failed fetching apresolve URL: Get \"https://apresolve.spotify.com/?type=accesspoint&type=dealer&type=spclient\": dial tcp: lookup apresolve.spotify.com: device or resource busy" Feb 16 20:53:19 znt systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 16 20:53:19 znt systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 16 20:53:21 znt volumio[1183]: info: Initializing connection to go-librespot Websocket Feb 16 20:53:21 znt volumio[1183]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 16 20:53:22 znt dhcpcd[923]: wlan0: leased 192.168.188.55 for 600 seconds Feb 16 20:53:22 znt avahi-daemon[813]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.188.55. Feb 16 20:53:22 znt avahi-daemon[813]: New relevant interface wlan0.IPv4 for mDNS. Feb 16 20:53:22 znt avahi-daemon[813]: Registering new address record for 192.168.188.55 on wlan0.IPv4. Feb 16 20:53:22 znt dhcpcd[923]: wlan0: adding route to 192.168.188.0/24 Feb 16 20:53:22 znt dhcpcd[923]: wlan0: adding default route via 192.168.188.1 Feb 16 20:53:22 znt systemd[1]: go-librespot-daemon.service: Service RestartSec=3s expired, scheduling restart. Feb 16 20:53:22 znt systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 16 20:53:22 znt systemd[1]: Stopped go-librespot Daemon. Feb 16 20:53:22 znt systemd[1]: Started go-librespot Daemon. Feb 16 20:53:22 znt go-librespot[13767]: Librespot-go daemon starting... Feb 16 20:53:22 znt go-librespot[13767]: time="2025-02-16T20:53:22Z" level=info msg="generated new device id: a76074b251cf329c7fa328724dbd9994c225b58e" Feb 16 20:53:22 znt go-librespot[13767]: time="2025-02-16T20:53:22Z" level=debug msg="stored credentials found for 316v3nxg7xb6isf4fs43ze7xzx6a" Feb 16 20:53:22 znt systemd[1]: Stopping Network Time Service... Feb 16 20:53:22 znt ntpd[12853]: ntpd exiting on signal 15 (Terminated) Feb 16 20:53:22 znt systemd[1]: ntp.service: Succeeded. Feb 16 20:53:22 znt volumio[1183]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 16 20:53:22 znt systemd[1]: Stopped Network Time Service. Feb 16 20:53:22 znt volumio[1183]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Feb 16 20:53:22 znt systemd[1]: Starting Network Time Service... Feb 16 20:53:22 znt volumio[1183]: ------------------------------------ BT MESSAGE: BT STATUS: running Feb 16 20:53:22 znt ntpd[13795]: ntpd 4.2.8p12@1.3728-o (1): Starting Feb 16 20:53:22 znt ntpd[13795]: Command line: /usr/sbin/ntpd -p /var/run/ntpd.pid -g -u 104:103 Feb 16 20:53:22 znt systemd[1]: Started Network Time Service. Feb 16 20:53:22 znt ntpd[13803]: proto: precision = 0.067 usec (-24) Feb 16 20:53:22 znt ntpd[13803]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): good hash signature Feb 16 20:53:22 znt ntpd[13803]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): loaded, expire=2022-12-28T00:00:00Z last=2017-01-01T00:00:00Z ofs=37 Feb 16 20:53:22 znt ntpd[13803]: leapsecond file ('/usr/share/zoneinfo/leap-seconds.list'): expired less than 782 days ago Feb 16 20:53:22 znt ntpd[13803]: Listen and drop on 0 v6wildcard [::]:123 Feb 16 20:53:22 znt ntpd[13803]: Listen and drop on 1 v4wildcard 0.0.0.0:123 Feb 16 20:53:22 znt ntpd[13803]: Listen normally on 2 lo 127.0.0.1:123 Feb 16 20:53:22 znt ntpd[13803]: Listen normally on 3 wlan0 192.168.188.55:123 Feb 16 20:53:22 znt ntpd[13803]: Listening on routing socket on fd #20 for interface updates Feb 16 20:53:22 znt ntpd[13803]: kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized Feb 16 20:53:22 znt ntpd[13803]: kernel reports TIME_ERROR: 0x2041: Clock Unsynchronized Feb 16 20:53:22 znt go-librespot[13767]: time="2025-02-16T20:53:22Z" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Feb 16 20:53:22 znt go-librespot[13767]: time="2025-02-16T20:53:22Z" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Feb 16 20:53:22 znt go-librespot[13767]: time="2025-02-16T20:53:22Z" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Feb 16 20:53:22 znt go-librespot[13767]: time="2025-02-16T20:53:22Z" level=debug msg="zeroconf server listening on port 42477" Feb 16 20:53:22 znt go-librespot[13767]: time="2025-02-16T20:53:22Z" level=debug msg="obtained new client token: AADQep7BfS8c8aSwP08Bp197+VtMn9IW+oPotSi1oqwXcBTkYwTkQBaYNfUJoOz9pWzck8v7RRytB2xuATevUeps+xBg0nyO8QExBHsHNLrLcCCwak8dgH1J+kWCN/n3gbOibkOqMiEARsyRBXxswMYl7diSa8b/LWvEFNqUU9/tjF6rUQZ1Karp3Flt/QrawnYJkAp2+XhODgudZwdhPKX7NKS4cUmHhNy51/wyQ9Jb3789DcxMindkE6oFdk0=" Feb 16 20:53:22 znt go-librespot[13767]: time="2025-02-16T20:53:22Z" level=info msg="connected to ap-gew4.spotify.com:4070" Feb 16 20:53:23 znt go-librespot[13767]: time="2025-02-16T20:53:23Z" level=debug msg="completed keyexchange" Feb 16 20:53:23 znt volumio[1183]: info: Discovery: adding 8ed8150d-16d0-4d16-a69e-65166cc88638 Feb 16 20:53:23 znt volumio[1183]: info: Discovery: Found device ZNT Feb 16 20:53:23 znt volumio[1183]: info: CoreCommandRouter::volumioGetState Feb 16 20:53:23 znt volumio[1183]: info: CorePlayQueue::getTrack 0 Feb 16 20:53:23 znt go-librespot[13767]: time="2025-02-16T20:53:23Z" level=debug msg="completed challenge" Feb 16 20:53:23 znt go-librespot[13767]: time="2025-02-16T20:53:23Z" level=debug msg="authenticated as 316v3nxg7xb6isf4fs43ze7xzx6a" Feb 16 20:53:23 znt ntpd[13803]: Soliciting pool server 185.13.148.71 Feb 16 20:53:23 znt go-librespot[13767]: time="2025-02-16T20:53:23Z" level=debug msg="authenticated as 316v3nxg7xb6isf4fs43ze7xzx6a" Feb 16 20:53:24 znt go-librespot[13767]: time="2025-02-16T20:53:24Z" level=debug msg="dealer connection opened" Feb 16 20:53:24 znt go-librespot[13767]: time="2025-02-16T20:53:24Z" level=debug msg="initializing zeroconf session, username: 316v3nxg7xb6isf4fs43ze7xzx6a" Feb 16 20:53:24 znt go-librespot[13767]: time="2025-02-16T20:53:24Z" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 16 20:53:24 znt go-librespot[13767]: time="2025-02-16T20:53:24Z" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 16 20:53:24 znt go-librespot[13767]: time="2025-02-16T20:53:24Z" level=debug msg="autoplay enabled: false" Feb 16 20:53:24 znt go-librespot[13767]: time="2025-02-16T20:53:24Z" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 16 20:53:24 znt go-librespot[13767]: time="2025-02-16T20:53:24Z" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 16 20:53:24 znt go-librespot[13767]: time="2025-02-16T20:53:24Z" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 16 20:53:24 znt go-librespot[13767]: time="2025-02-16T20:53:24Z" level=debug msg="received connection id: YTk2YTEwOWItMTBkMy00NmM2LWFjY2EtYTQ2OTA2MmRhZjMyK2RlYWxlcit0Y3A6Ly8wYWNhNWEwZS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNTQyRjUxMzY2MEU5N0E5OEY1Q0RCNTM2RjlFRDNCMjBDMDZENTM4Q0UzNTRENDY4RDFEMjFCRTdBQTE4NEM0QQ==" Feb 16 20:53:24 znt volumio[1183]: info: Initializing connection to go-librespot Websocket Feb 16 20:53:24 znt go-librespot[13767]: time="2025-02-16T20:53:24Z" level=debug msg="new websocket client" Feb 16 20:53:24 znt volumio[1183]: info: Connection to go-librespot Websocket established Feb 16 20:53:24 znt go-librespot[13767]: time="2025-02-16T20:53:24Z" level=debug msg="put connect state because NEW_DEVICE" Feb 16 20:53:24 znt ntpd[13803]: Soliciting pool server 144.76.66.156 Feb 16 20:53:24 znt ntpd[13803]: Soliciting pool server 167.235.139.237 Feb 16 20:53:25 znt ntpd[13803]: Soliciting pool server 79.133.44.139 Feb 16 20:53:25 znt ntpd[13803]: Soliciting pool server 116.202.118.202 Feb 16 20:53:25 znt ntpd[13803]: Soliciting pool server 185.41.106.152 Feb 16 20:53:25 znt volumio[1183]: info: Volumio Network Manager: Network status updated: 2 Feb 16 20:53:26 znt ntpd[13803]: Soliciting pool server 162.159.200.1 Feb 16 20:53:26 znt ntpd[13803]: Soliciting pool server 194.164.164.175 Feb 16 20:53:26 znt ntpd[13803]: Soliciting pool server 130.162.222.153 Feb 16 20:53:26 znt ntpd[13803]: Soliciting pool server 157.90.16.149 Feb 16 20:53:27 znt volumio[1183]: info: Getting Spotify volume Feb 16 20:53:27 znt volumio[1183]: info: Spotify volume: 100 Feb 16 20:53:27 znt volumio[1183]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Feb 16 20:53:27 znt volumio[1183]: info: CoreCommandRouter::volumioGetState Feb 16 20:53:27 znt volumio[1183]: info: CorePlayQueue::getTrack 0 Feb 16 20:53:27 znt volumio[1183]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 16 20:53:27 znt ntpd[13803]: Soliciting pool server 89.58.43.2 Feb 16 20:53:27 znt ntpd[13803]: Soliciting pool server 213.209.109.44 Feb 16 20:53:27 znt ntpd[13803]: Soliciting pool server 62.108.36.235 Feb 16 20:53:28 znt ntpd[13803]: Soliciting pool server 188.174.253.188 Feb 16 20:53:28 znt ntpd[13803]: Soliciting pool server 129.70.132.36 Feb 16 20:53:29 znt ntpd[13803]: Soliciting pool server 31.209.85.242 Feb 16 20:53:29 znt ntpd[13803]: Soliciting pool server 2001:678:8::123 Feb 16 20:53:31 znt volumio[1183]: Searching plugin music_service/last_100 Feb 16 20:53:31 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Feb 16 20:53:31 znt volumio[1183]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Feb 16 20:53:31 znt volumio[1183]: info: All search sources collected, pushing search results Feb 16 20:53:33 znt volumio[1183]: Searching plugin music_service/last_100 Feb 16 20:53:33 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: last_100 , search Feb 16 20:53:33 znt volumio[1183]: info: Error : CoreCommandRouter::executeOnPlugin: No method [search] in plugin last_100 Feb 16 20:53:33 znt volumio[1183]: info: All search sources collected, pushing search results Feb 16 20:53:39 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Feb 16 20:53:39 znt volumio[1183]: info: In handleBrowseUri, curUri=spotify Feb 16 20:53:40 znt volumio[1183]: info: Preload queue cleared Feb 16 20:53:48 znt volumio[1183]: Searching plugin music_service/spop Feb 16 20:53:48 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 16 20:53:49 znt volumio[1183]: info: All search sources collected, pushing search results Feb 16 20:53:52 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Feb 16 20:53:52 znt volumio[1183]: info: In handleBrowseUri, curUri=spotify:artist:5poyNTy0YyDwAMSYBJ7zgv Feb 16 20:53:53 znt volumio[1183]: info: Preload queue cleared Feb 16 20:53:53 znt volumio[1183]: info: Preloading song: spotify:track:3wECJLFkS6cGvdyVOmGFme Feb 16 20:53:53 znt volumio[1183]: info: Preloading song: spotify:track:1VkWnzaLC189MYggfFEDVY Feb 16 20:53:53 znt volumio[1183]: info: Preloading song: spotify:track:2f7yxVf3k37e1YKEyJENw2 Feb 16 20:53:53 znt volumio[1183]: info: Preloading song: spotify:track:1N9FukjNaljt9MUzjzQ64J Feb 16 20:53:53 znt volumio[1183]: info: Preloading song: spotify:track:3d6EsUcyzgzdcvcG65iRZG Feb 16 20:53:53 znt volumio[1183]: info: Preloading song: spotify:track:3QMeN6MPTrLVH9wIbwQm6y Feb 16 20:53:53 znt volumio[1183]: info: Preloading song: spotify:track:0HW4PCN1FdBa65c5IXv8S7 Feb 16 20:53:53 znt volumio[1183]: info: Preloading song: spotify:track:0ONwYl521R4E2fs1WzZ6qD Feb 16 20:53:53 znt volumio[1183]: info: Preloading song: spotify:track:0iLyAlInsomkzvxAMYlS6R Feb 16 20:53:53 znt volumio[1183]: info: Preloading song: spotify:track:7xJPa1jms8mgBnxuxKmVuw Feb 16 20:53:53 znt volumio[1183]: info: Preload queue cleared Feb 16 20:53:54 znt volumio[1183]: info: Executing endpoint getSimilarArtists Feb 16 20:53:54 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 16 20:53:54 znt volumio[1183]: info: Executing endpoint getSimilarArtists Feb 16 20:53:54 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 16 20:53:54 znt volumio[1183]: info: Executing endpoint getSimilarArtists Feb 16 20:53:54 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 16 20:53:54 znt volumio[1183]: info: Executing endpoint getSimilarArtists Feb 16 20:53:54 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 16 20:53:54 znt volumio[1183]: info: Executing endpoint getSimilarArtists Feb 16 20:53:54 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 16 20:53:54 znt volumio[1183]: info: Executing endpoint getSimilarArtists Feb 16 20:53:54 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 16 20:53:55 znt volumio[1183]: info: Executing endpoint getSimilarArtists Feb 16 20:53:55 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 16 20:53:55 znt volumio[1183]: info: Executing endpoint getSimilarArtists Feb 16 20:53:55 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 16 20:53:55 znt volumio[1183]: info: Executing endpoint getSimilarArtists Feb 16 20:53:55 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 16 20:53:55 znt volumio[1183]: info: Executing endpoint getSimilarArtists Feb 16 20:53:55 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getSimilarArtists Feb 16 20:53:56 znt volumio[1183]: info: Executing endpoint metavolumio Feb 16 20:53:56 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 16 20:53:56 znt volumio[1183]: info: Executing endpoint metavolumio Feb 16 20:53:56 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 16 20:53:56 znt volumio[1183]: info: Executing endpoint metavolumio Feb 16 20:53:56 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 16 20:53:56 znt volumio[1183]: info: Executing endpoint metavolumio Feb 16 20:53:56 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 16 20:53:56 znt volumio[1183]: error: Failed request for metavolumio API Feb 16 20:53:56 znt volumio[1183]: info: Executing endpoint metavolumio Feb 16 20:53:56 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 16 20:53:57 znt volumio[1183]: info: Executing endpoint metavolumio Feb 16 20:53:57 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 16 20:53:57 znt volumio[1183]: info: Executing endpoint metavolumio Feb 16 20:53:57 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 16 20:53:57 znt volumio[1183]: info: Executing endpoint metavolumio Feb 16 20:53:57 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 16 20:53:58 znt volumio[1183]: info: Executing endpoint metavolumio Feb 16 20:53:58 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 16 20:53:59 znt volumio[1183]: info: Preload queue cleared Feb 16 20:53:59 znt volumio[1183]: info: CoreCommandRouter::volumioReplaceandPlayItems Feb 16 20:53:59 znt volumio[1183]: info: CoreStateMachine::ClearQueue Feb 16 20:53:59 znt volumio[1183]: info: CoreStateMachine::stop Feb 16 20:53:59 znt volumio[1183]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 16 20:53:59 znt volumio[1183]: info: CorePlayQueue::clearPlayQueue Feb 16 20:53:59 znt volumio[1183]: info: CorePlayQueue::saveQueue Feb 16 20:53:59 znt volumio[1183]: info: CoreCommandRouter::volumioPushQueue Feb 16 20:53:59 znt volumio[1183]: info: CoreStateMachine::addQueueItems Feb 16 20:53:59 znt volumio[1183]: info: CorePlayQueue::addQueueItems Feb 16 20:53:59 znt volumio[1183]: info: Preload queue cleared Feb 16 20:53:59 znt volumio[1183]: info: Adding Item to queue: spotify:track:3wECJLFkS6cGvdyVOmGFme Feb 16 20:53:59 znt volumio[1183]: info: Exploding uri spotify:track:3wECJLFkS6cGvdyVOmGFme in service spop Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:3wECJLFkS6cGvdyVOmGFme Feb 16 20:53:59 znt volumio[1183]: info: Adding Item to queue: spotify:track:1VkWnzaLC189MYggfFEDVY Feb 16 20:53:59 znt volumio[1183]: info: Exploding uri spotify:track:1VkWnzaLC189MYggfFEDVY in service spop Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:1VkWnzaLC189MYggfFEDVY Feb 16 20:53:59 znt volumio[1183]: info: Adding Item to queue: spotify:track:2f7yxVf3k37e1YKEyJENw2 Feb 16 20:53:59 znt volumio[1183]: info: Exploding uri spotify:track:2f7yxVf3k37e1YKEyJENw2 in service spop Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:2f7yxVf3k37e1YKEyJENw2 Feb 16 20:53:59 znt volumio[1183]: info: Adding Item to queue: spotify:track:1N9FukjNaljt9MUzjzQ64J Feb 16 20:53:59 znt volumio[1183]: info: Exploding uri spotify:track:1N9FukjNaljt9MUzjzQ64J in service spop Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:1N9FukjNaljt9MUzjzQ64J Feb 16 20:53:59 znt volumio[1183]: info: Adding Item to queue: spotify:track:3d6EsUcyzgzdcvcG65iRZG Feb 16 20:53:59 znt volumio[1183]: info: Exploding uri spotify:track:3d6EsUcyzgzdcvcG65iRZG in service spop Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:3d6EsUcyzgzdcvcG65iRZG Feb 16 20:53:59 znt volumio[1183]: info: Adding Item to queue: spotify:track:3QMeN6MPTrLVH9wIbwQm6y Feb 16 20:53:59 znt volumio[1183]: info: Exploding uri spotify:track:3QMeN6MPTrLVH9wIbwQm6y in service spop Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:3QMeN6MPTrLVH9wIbwQm6y Feb 16 20:53:59 znt volumio[1183]: info: Adding Item to queue: spotify:track:0HW4PCN1FdBa65c5IXv8S7 Feb 16 20:53:59 znt volumio[1183]: info: Exploding uri spotify:track:0HW4PCN1FdBa65c5IXv8S7 in service spop Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:0HW4PCN1FdBa65c5IXv8S7 Feb 16 20:53:59 znt volumio[1183]: info: Adding Item to queue: spotify:track:0ONwYl521R4E2fs1WzZ6qD Feb 16 20:53:59 znt volumio[1183]: info: Exploding uri spotify:track:0ONwYl521R4E2fs1WzZ6qD in service spop Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:0ONwYl521R4E2fs1WzZ6qD Feb 16 20:53:59 znt volumio[1183]: info: Adding Item to queue: spotify:track:0iLyAlInsomkzvxAMYlS6R Feb 16 20:53:59 znt volumio[1183]: info: Exploding uri spotify:track:0iLyAlInsomkzvxAMYlS6R in service spop Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:0iLyAlInsomkzvxAMYlS6R Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0HW4PCN1FdBa65c5IXv8S7","service":"spop","name":"Wir räumen auf","artist":"Lichterkinder","album":"Gemeinsam sind wir stark (Spiel-, Spaß- Und Lernlieder)","type":"song","duration":117,"albumart":"https://i.scdn.co/image/ab67616d0000b273eb0fb77ecf046d5484e62d24","samplerate":"96 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3wECJLFkS6cGvdyVOmGFme","service":"spop","name":"Der Körperteil Blues","artist":"Lichterkinder","album":"Spiel - und Bewegungslieder","type":"song","duration":237,"albumart":"https://i.scdn.co/image/ab67616d0000b273344e67cc3b14d91556d63597","samplerate":"96 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1VkWnzaLC189MYggfFEDVY","service":"spop","name":"Guck mal diese Biene da Summ Summ","artist":"Lichterkinder","album":"Spiel- und Bewegungslieder auf Weltreise","type":"song","duration":176,"albumart":"https://i.scdn.co/image/ab67616d0000b273761ee00220f48336a35d6b1c","samplerate":"96 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0ONwYl521R4E2fs1WzZ6qD","service":"spop","name":"Die Maus auf Weltraumreise","artist":"Lichterkinder","album":"Spiel - und Bewegungslieder","type":"song","duration":262,"albumart":"https://i.scdn.co/image/ab67616d0000b273344e67cc3b14d91556d63597","samplerate":"96 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:1N9FukjNaljt9MUzjzQ64J","service":"spop","name":"Fünf kleine Fische","artist":"Lichterkinder","album":"Spiel - und Bewegungslieder","type":"song","duration":120,"albumart":"https://i.scdn.co/image/ab67616d0000b273344e67cc3b14d91556d63597","samplerate":"96 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:0iLyAlInsomkzvxAMYlS6R","service":"spop","name":"Lichterkinder","artist":"Lichterkinder","album":"Laternen- und Herbstlieder","type":"song","duration":241,"albumart":"https://i.scdn.co/image/ab67616d0000b273f48f07d5741163fbff3953d6","samplerate":"96 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3d6EsUcyzgzdcvcG65iRZG","service":"spop","name":"Aramsamsam","artist":"Lichterkinder","album":"Spiel - und Bewegungslieder","type":"song","duration":166,"albumart":"https://i.scdn.co/image/ab67616d0000b273344e67cc3b14d91556d63597","samplerate":"96 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:2f7yxVf3k37e1YKEyJENw2","service":"spop","name":"Samba, Rumba, Cha Cha Cha","artist":"Lichterkinder","album":"Spiel - und Bewegungslieder","type":"song","duration":129,"albumart":"https://i.scdn.co/image/ab67616d0000b273344e67cc3b14d91556d63597","samplerate":"96 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:3QMeN6MPTrLVH9wIbwQm6y","service":"spop","name":"La Le Lu","artist":"Lichterkinder","album":"Schlaflieder","type":"song","duration":130,"albumart":"https://i.scdn.co/image/ab67616d0000b273ef7e84669bee19015dea752f","samplerate":"96 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Feb 16 20:53:59 znt volumio[1183]: info: CoreCommandRouter::volumioPushQueue Feb 16 20:53:59 znt volumio[1183]: info: CorePlayQueue::saveQueue Feb 16 20:53:59 znt volumio[1183]: info: CoreStateMachine::updateTrackBlock Feb 16 20:53:59 znt volumio[1183]: info: CorePlayQueue::getTrackBlock Feb 16 20:53:59 znt volumio[1183]: info: CoreCommandRouter::volumioPlay Feb 16 20:53:59 znt volumio[1183]: info: CoreStateMachine::play index 8 Feb 16 20:53:59 znt volumio[1183]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 16 20:53:59 znt volumio[1183]: info: CoreStateMachine::addQueueItems Feb 16 20:53:59 znt volumio[1183]: info: CorePlayQueue::addQueueItems Feb 16 20:53:59 znt volumio[1183]: info: Preload queue cleared Feb 16 20:53:59 znt volumio[1183]: info: Adding Item to queue: spotify:track:7xJPa1jms8mgBnxuxKmVuw Feb 16 20:53:59 znt volumio[1183]: info: Exploding uri spotify:track:7xJPa1jms8mgBnxuxKmVuw in service spop Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: EXPLODING URI:spotify:track:7xJPa1jms8mgBnxuxKmVuw Feb 16 20:53:59 znt volumio[1183]: info: CoreStateMachine::stop Feb 16 20:53:59 znt volumio[1183]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 16 20:53:59 znt volumio[1183]: info: CoreStateMachine::play index undefined Feb 16 20:53:59 znt volumio[1183]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 16 20:53:59 znt volumio[1183]: info: CorePlayQueue::getTrack 8 Feb 16 20:53:59 znt volumio[1183]: info: CoreStateMachine::startPlaybackTimer Feb 16 20:53:59 znt volumio[1183]: info: CorePlayQueue::getTrack 8 Feb 16 20:53:59 znt volumio[1183]: info: CoreCommandRouter::volumioGetVisibleSources Feb 16 20:53:59 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 16 20:53:59 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Feb 16 20:53:59 znt volumio[1183]: info: [1739739239319] ControllerSpotify::clearAddPlayTrack Feb 16 20:53:59 znt volumio[1183]: info: Sending Spotify command with payload to local API: /player/play Feb 16 20:53:59 znt go-librespot[13767]: time="2025-02-16T20:53:59Z" level=debug msg="resolved context of track" uri="spotify:track:0iLyAlInsomkzvxAMYlS6R" Feb 16 20:53:59 znt go-librespot[13767]: time="2025-02-16T20:53:59Z" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:0iLyAlInsomkzvxAMYlS6R" Feb 16 20:53:59 znt go-librespot[13767]: time="2025-02-16T20:53:59Z" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:0iLyAlInsomkzvxAMYlS6R" Feb 16 20:53:59 znt volumio[1183]: info: Executing endpoint metavolumio Feb 16 20:53:59 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Feb 16 20:53:59 znt go-librespot[13767]: time="2025-02-16T20:53:59Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 16 20:53:59 znt go-librespot[13767]: time="2025-02-16T20:53:59Z" level=trace msg="emitting websocket event: will_play" Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:0iLyAlInsomkzvxAMYlS6R","play_origin":"go-librespot"}} Feb 16 20:53:59 znt volumio[1183]: SPOTIFY: GET TRACK: [{"uri":"spotify:track:7xJPa1jms8mgBnxuxKmVuw","service":"spop","name":"Der Herbst ist da","artist":"Lichterkinder","album":"Laternen- und Herbstlieder","type":"song","duration":109,"albumart":"https://i.scdn.co/image/ab67616d0000b273f48f07d5741163fbff3953d6","samplerate":"96 kbps","bitdepth":"16 bit","bitrate":"","codec":"ogg","trackType":"spotify"}] Feb 16 20:53:59 znt volumio[1183]: info: CoreCommandRouter::volumioPushQueue Feb 16 20:53:59 znt volumio[1183]: info: CorePlayQueue::saveQueue Feb 16 20:53:59 znt volumio[1183]: info: CoreStateMachine::updateTrackBlock Feb 16 20:53:59 znt volumio[1183]: info: CorePlayQueue::getTrackBlock Feb 16 20:53:59 znt go-librespot[13767]: time="2025-02-16T20:53:59Z" level=debug msg="selected format OGG_VORBIS_96 (0984befea9388454fd9f72533205de5d8c8e2ef9)" uri="spotify:track:0iLyAlInsomkzvxAMYlS6R" Feb 16 20:53:59 znt go-librespot[13767]: time="2025-02-16T20:53:59Z" level=debug msg="requested aes key for file 0984befea9388454fd9f72533205de5d8c8e2ef9, gid: 0iLyAlInsomkzvxAMYlS6R" Feb 16 20:54:00 znt go-librespot[13767]: time="2025-02-16T20:54:00Z" level=debug msg="fetched first chunk of 6, total size is 2882156 bytes" uri="spotify:track:0iLyAlInsomkzvxAMYlS6R" Feb 16 20:54:00 znt go-librespot[13767]: time="2025-02-16T20:54:00Z" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:0iLyAlInsomkzvxAMYlS6R" Feb 16 20:54:00 znt go-librespot[13767]: time="2025-02-16T20:54:00Z" level=debug msg="created new output device" Feb 16 20:54:00 znt go-librespot[13767]: time="2025-02-16T20:54:00Z" level=info msg="loaded track \"Lichterkinder\" (paused: false, position: 0ms, duration: 241133ms, prefetched: false)" uri="spotify:track:0iLyAlInsomkzvxAMYlS6R" Feb 16 20:54:00 znt go-librespot[13767]: time="2025-02-16T20:54:00Z" level=debug msg="fetched chunk 1/5, size: 524288" uri="spotify:track:0iLyAlInsomkzvxAMYlS6R" Feb 16 20:54:00 znt go-librespot[13767]: time="2025-02-16T20:54:00Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 16 20:54:00 znt go-librespot[13767]: time="2025-02-16T20:54:00Z" level=trace msg="scheduling prefetch in 211s" Feb 16 20:54:00 znt go-librespot[13767]: time="2025-02-16T20:54:00Z" level=trace msg="emitting websocket event: metadata" Feb 16 20:54:00 znt volumio[1183]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0iLyAlInsomkzvxAMYlS6R","name":"Lichterkinder","artist_names":["Lichterkinder"],"album_name":"Laternen- und Herbstlieder","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02f48f07d5741163fbff3953d6","position":0,"duration":241133,"release_date":"year:2016 month:9 day:16","track_number":1,"disc_number":1}} Feb 16 20:54:00 znt go-librespot[13767]: time="2025-02-16T20:54:00Z" level=debug msg="fetched chunk 2/5, size: 524288" uri="spotify:track:0iLyAlInsomkzvxAMYlS6R" Feb 16 20:54:00 znt go-librespot[13767]: time="2025-02-16T20:54:00Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 16 20:54:00 znt go-librespot[13767]: time="2025-02-16T20:54:00Z" level=trace msg="emitting websocket event: playing" Feb 16 20:54:00 znt volumio[1183]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:0iLyAlInsomkzvxAMYlS6R","play_origin":"go-librespot"}} Feb 16 20:54:00 znt volumio[1183]: SPOTIFY: PUSH STATE SPOTIFY Feb 16 20:54:00 znt volumio[1183]: SPOTIFY: {"status":"play","service":"spop","title":"Lichterkinder","artist":"Lichterkinder","album":"Laternen- und Herbstlieder","albumart":"https://i.scdn.co/image/ab67616d00001e02f48f07d5741163fbff3953d6","uri":"spotify:track:0iLyAlInsomkzvxAMYlS6R","trackType":"spotify","seek":0,"duration":241,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"96 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 16 20:54:00 znt volumio[1183]: info: CoreCommandRouter::servicePushState Feb 16 20:54:00 znt volumio[1183]: info: CorePlayQueue::getTrack 8 Feb 16 20:54:00 znt volumio[1183]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Lichterkinder","artist":"Lichterkinder","album":"Laternen- und Herbstlieder","albumart":"https://i.scdn.co/image/ab67616d00001e02f48f07d5741163fbff3953d6","uri":"spotify:track:0iLyAlInsomkzvxAMYlS6R","trackType":"spotify","seek":0,"duration":241,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"96 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 16 20:54:00 znt volumio[1183]: verbose: CURRENT POSITION 8 Feb 16 20:54:00 znt volumio[1183]: info: CoreStateMachine::syncState stateService play Feb 16 20:54:00 znt volumio[1183]: info: CoreStateMachine::syncState currentStatus stop Feb 16 20:54:00 znt go-librespot[13767]: time="2025-02-16T20:54:00Z" level=debug msg="fetched chunk 3/5, size: 524288" uri="spotify:track:0iLyAlInsomkzvxAMYlS6R" Feb 16 20:54:00 znt volumio[1183]: SPOTIFY: PUSH STATE SPOTIFY Feb 16 20:54:00 znt volumio[1183]: SPOTIFY: {"status":"play","service":"spop","title":"Lichterkinder","artist":"Lichterkinder","album":"Laternen- und Herbstlieder","albumart":"https://i.scdn.co/image/ab67616d00001e02f48f07d5741163fbff3953d6","uri":"spotify:track:0iLyAlInsomkzvxAMYlS6R","trackType":"spotify","seek":0,"duration":241,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"96 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 16 20:54:00 znt volumio[1183]: info: CoreCommandRouter::servicePushState Feb 16 20:54:00 znt volumio[1183]: info: CorePlayQueue::getTrack 8 Feb 16 20:54:00 znt volumio[1183]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Lichterkinder","artist":"Lichterkinder","album":"Laternen- und Herbstlieder","albumart":"https://i.scdn.co/image/ab67616d00001e02f48f07d5741163fbff3953d6","uri":"spotify:track:0iLyAlInsomkzvxAMYlS6R","trackType":"spotify","seek":0,"duration":241,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"96 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 16 20:54:00 znt volumio[1183]: verbose: CURRENT POSITION 8 Feb 16 20:54:00 znt volumio[1183]: info: CoreStateMachine::syncState stateService play Feb 16 20:54:00 znt volumio[1183]: info: CoreStateMachine::syncState currentStatus play Feb 16 20:54:00 znt volumio[1183]: info: Received an update from plugin. extracting info from payload Feb 16 20:54:00 znt volumio[1183]: info: CoreStateMachine::pushState Feb 16 20:54:00 znt volumio[1183]: info: CorePlayQueue::getTrack 8 Feb 16 20:54:00 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 16 20:54:00 znt volumio[1183]: info: CoreCommandRouter::volumioPushState Feb 16 20:54:00 znt volumio[1183]: info: MRS: Pushing multiroomSync output update for this device Feb 16 20:54:00 znt volumio[1183]: info: MRS: Pushing multiroomSync output Feb 16 20:54:00 znt volumio[1183]: info: CoreStateMachine::pushState Feb 16 20:54:00 znt volumio[1183]: info: CorePlayQueue::getTrack 8 Feb 16 20:54:00 znt volumio[1183]: info: CoreCommandRouter::volumioPushState Feb 16 20:54:00 znt volumio[1183]: info: MRS: Pushing multiroomSync output update for this device Feb 16 20:54:00 znt volumio[1183]: info: MRS: Pushing multiroomSync output Feb 16 20:54:00 znt volumio[1183]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 16 20:54:20 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 16 20:54:20 znt volumio[1183]: info: Preload queue cleared Feb 16 20:54:21 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 16 20:54:22 znt volumio[1183]: info: Preload queue cleared Feb 16 20:54:24 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 16 20:54:24 znt volumio[1183]: info: Preload queue cleared Feb 16 20:54:30 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 16 20:54:30 znt volumio[1183]: info: Preload queue cleared Feb 16 20:54:30 znt volumio[1183]: info: Preloading song: upnp/http://192.168.188.21:50001/ContentDirectory/control@22$@1 Feb 16 20:54:30 znt volumio[1183]: info: Exploding uri upnp/http://192.168.188.21:50001/ContentDirectory/control@22$@1 in service upnp_browser Feb 16 20:54:33 znt volumio[1183]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Feb 16 20:54:33 znt volumio[1183]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 16 20:54:33 znt volumio[1183]: TypeError: Cannot read property 'length' of undefined Feb 16 20:54:33 znt volumio[1183]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Feb 16 20:54:33 znt volumio[1183]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Feb 16 20:54:33 znt volumio[1183]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Feb 16 20:54:33 znt volumio[1183]: at Parser.emit (events.js:400:28) Feb 16 20:54:33 znt volumio[1183]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Feb 16 20:54:33 znt volumio[1183]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Feb 16 20:54:33 znt volumio[1183]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Feb 16 20:54:33 znt volumio[1183]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Feb 16 20:54:33 znt volumio[1183]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Feb 16 20:54:33 znt volumio[1183]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Feb 16 20:54:33 znt volumio[1183]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Feb 16 20:54:33 znt volumio[1183]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Feb 16 20:54:33 znt volumio[1183]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Feb 16 20:54:33 znt volumio[1183]: at IncomingMessage.emit (events.js:412:35) Feb 16 20:54:33 znt volumio[1183]: at endReadableNT (internal/streams/readable.js:1333:12) Feb 16 20:54:33 znt volumio[1183]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Feb 16 20:54:33 znt volumio[1183]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 16 20:54:33 znt sudo[13985]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-16 20:53 Feb 16 20:54:33 znt sudo[13985]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 07:25:16 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="66c567362bdbb3dc1644a18f7879afe7"