-- Logs begin at Thu 2019-02-14 10:11:59 UTC, end at Wed 2025-04-23 12:22:59 UTC. -- Apr 23 12:21:04 volumio go-librespot[11293]: time="2025-04-23T12:21:04Z" level=error msg="failed receiving dealer message" error="failed to get reader: WebSocket closed: sent close frame: status = StatusServiceRestart and reason = \"\"" Apr 23 12:21:23 volumio go-librespot[11293]: time="2025-04-23T12:21:23Z" level=debug msg="selected format OGG_VORBIS_320 (5d58554c228c6755177db450834c0bc5f025d1fa)" uri="spotify:track:4EcQ8GHyJGLw45jkA9SzmD" Apr 23 12:21:23 volumio go-librespot[11293]: time="2025-04-23T12:21:23Z" level=debug msg="requested aes key for file 5d58554c228c6755177db450834c0bc5f025d1fa, gid: 4EcQ8GHyJGLw45jkA9SzmD" Apr 23 12:21:29 volumio go-librespot[11293]: time="2025-04-23T12:21:29Z" level=error msg="did not receive last pong from dealer, 90s passed" Apr 23 12:21:30 volumio nmbd[737]: [2025/04/23 12:21:30.300641, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) Apr 23 12:21:30 volumio nmbd[737]: query_name_response: Multiple (2) responses received for a query on subnet 10.9.8.70 for name WORKGROUP<1d>. Apr 23 12:21:30 volumio nmbd[737]: This response was from IP 10.9.8.58, reporting an IP address of 10.9.8.58. Apr 23 12:21:33 volumio go-librespot[11293]: time="2025-04-23T12:21:33Z" level=debug msg="re-established dealer connection" Apr 23 12:21:37 volumio go-librespot[11293]: time="2025-04-23T12:21:37Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 12:21:37 volumio go-librespot[11293]: time="2025-04-23T12:21:37Z" level=trace msg="emitting websocket event: will_play" Apr 23 12:21:37 volumio volumio[1185]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:4EcQ8GHyJGLw45jkA9SzmD","play_origin":"album"}} Apr 23 12:21:37 volumio go-librespot[11293]: time="2025-04-23T12:21:37Z" level=debug msg="selected format OGG_VORBIS_320 (5d58554c228c6755177db450834c0bc5f025d1fa)" uri="spotify:track:4EcQ8GHyJGLw45jkA9SzmD" Apr 23 12:21:37 volumio go-librespot[11293]: time="2025-04-23T12:21:37Z" level=debug msg="requested aes key for file 5d58554c228c6755177db450834c0bc5f025d1fa, gid: 4EcQ8GHyJGLw45jkA9SzmD" Apr 23 12:22:25 volumio dhcpcd[994]: eth0: failed to renew DHCP, rebinding Apr 23 12:22:25 volumio dhcpcd[994]: eth0: adding route to 10.9.8.0/24 Apr 23 12:22:25 volumio dhcpcd[994]: eth0: adding default route via 10.9.8.254 Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=debug msg="fetched first chunk of 16, total size is 8283040 bytes" uri="spotify:track:4EcQ8GHyJGLw45jkA9SzmD" Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=debug msg="fetched first chunk of 16, total size is 8283040 bytes" uri="spotify:track:4EcQ8GHyJGLw45jkA9SzmD" Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:4EcQ8GHyJGLw45jkA9SzmD" Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:4EcQ8GHyJGLw45jkA9SzmD" Apr 23 12:22:54 volumio volumio[1185]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Apr 23 12:22:54 volumio volumio[1185]: info: FusionDsp - ---- read samplerate from file: 44100 Apr 23 12:22:54 volumio volumio[1185]: info: FusionDsp - If filter freq >samplerate/2 then disable it Apr 23 12:22:54 volumio volumio[1185]: info: FusionDsp - crossfeed nc_11_50 Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=debug msg="created new output device" Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=info msg="prefetched track \"Green\" (duration: 228027ms)" uri="spotify:track:4EcQ8GHyJGLw45jkA9SzmD" Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=info msg="loaded track \"Green\" (paused: false, position: 0ms, duration: 228027ms, prefetched: false)" uri="spotify:track:4EcQ8GHyJGLw45jkA9SzmD" Apr 23 12:22:54 volumio volumio[1185]: info: FusionDsp - {"Reload":{"result":"Ok"}} Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:4EcQ8GHyJGLw45jkA9SzmD" Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:4EcQ8GHyJGLw45jkA9SzmD" Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=trace msg="scheduling prefetch in 197s" Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=trace msg="emitting websocket event: metadata" Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=debug msg="received connection id: ZTFmNDc3YTktNjlhMS00ZThkLWFiN2UtMDA2OTgwNjg0NDQzK2RlYWxlcit0Y3A6Ly8wYWM5NGIwYi5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArQjE3MTcxRTJCNThCNDkzMjI1NTkzODY5MTZCNEVBOTFCQUM0MjNGNzE3OEYxMDEyRDJCMzQxQzc5NzZEREY2QQ==" Apr 23 12:22:54 volumio volumio[1185]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:4EcQ8GHyJGLw45jkA9SzmD","name":"Green","artist_names":["Four Tet"],"album_name":"Sixteen Oceans","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02210e19d835bb0af6620256cf","position":0,"duration":228027,"release_date":"year:2020 month:3 day:13","track_number":12,"disc_number":1}} Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=debug msg="put connect state because NEW_DEVICE" Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=trace msg="emitting websocket event: stopped" Apr 23 12:22:54 volumio volumio[1185]: SPOTIFY: received: {"type":"stopped","data":{"play_origin":"album"}} Apr 23 12:22:54 volumio volumio[1185]: SPOTIFY: PUSH STATE SPOTIFY Apr 23 12:22:54 volumio volumio[1185]: SPOTIFY: {"status":"stop","service":"spop","title":"Green","artist":"Four Tet","album":"Sixteen Oceans","albumart":"https://i.scdn.co/image/ab67616d00001e02210e19d835bb0af6620256cf","uri":"spotify:track:4EcQ8GHyJGLw45jkA9SzmD","trackType":"spotify","seek":0,"duration":228,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 23 12:22:54 volumio volumio[1185]: info: CoreCommandRouter::servicePushState Apr 23 12:22:54 volumio volumio[1185]: info: CoreStateMachine::pushState Apr 23 12:22:54 volumio volumio[1185]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 23 12:22:54 volumio volumio[1185]: info: CoreCommandRouter::volumioPushState Apr 23 12:22:54 volumio volumio[1185]: info: CorePlayQueue::getTrack 0 Apr 23 12:22:54 volumio volumio[1185]: verbose: STATE SERVICE {"status":"stop","service":"spop","title":"Green","artist":"Four Tet","album":"Sixteen Oceans","albumart":"https://i.scdn.co/image/ab67616d00001e02210e19d835bb0af6620256cf","uri":"spotify:track:4EcQ8GHyJGLw45jkA9SzmD","trackType":"spotify","seek":0,"duration":228,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 23 12:22:54 volumio volumio[1185]: verbose: CURRENT POSITION 0 Apr 23 12:22:54 volumio volumio[1185]: info: CoreStateMachine::syncState stateService stop Apr 23 12:22:54 volumio volumio[1185]: info: CoreStateMachine::syncState currentStatus play Apr 23 12:22:54 volumio volumio[1185]: info: CoreCommandRouter::volumioPushState Apr 23 12:22:54 volumio volumio[1185]: info: CoreStateMachine::stPlaybackTimer Apr 23 12:22:54 volumio volumio[1185]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:4EcQ8GHyJGLw45jkA9SzmD" Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:4EcQ8GHyJGLw45jkA9SzmD" Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:4EcQ8GHyJGLw45jkA9SzmD" Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:4EcQ8GHyJGLw45jkA9SzmD" Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 23 12:22:54 volumio go-librespot[11293]: time="2025-04-23T12:22:54Z" level=trace msg="emitting websocket event: playing" Apr 23 12:22:54 volumio volumio[1185]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:4EcQ8GHyJGLw45jkA9SzmD","play_origin":"album"}} Apr 23 12:22:54 volumio volumio[1185]: info: Spotify is playing in volatile mode Apr 23 12:22:54 volumio volumio[1185]: info: CoreStateMachine::setConsumeUpdateService undefined Apr 23 12:22:54 volumio volumio[1185]: SPOTIFY: UNSET VOLATILE Apr 23 12:22:54 volumio volumio[1185]: SPOTIFY: {"status":"stop","position":0,"title":"","artist":"","album":"","albumart":"/albumart","duration":0,"uri":"","seek":0,"samplerate":"","channels":"","bitdepth":"","Streaming":false,"service":"mpd","volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":false,"random":false,"repeat":false,"repeatSingle":false,"consume":false} Apr 23 12:22:54 volumio volumio[1185]: SPOTIFY: PUSH STATE SPOTIFY Apr 23 12:22:54 volumio volumio[1185]: SPOTIFY: {"status":"play","service":"spop","title":"Green","artist":"Four Tet","album":"Sixteen Oceans","albumart":"https://i.scdn.co/image/ab67616d00001e02210e19d835bb0af6620256cf","uri":"spotify:track:4EcQ8GHyJGLw45jkA9SzmD","trackType":"spotify","seek":0,"duration":228,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 23 12:22:54 volumio volumio[1185]: info: CoreCommandRouter::servicePushState Apr 23 12:22:54 volumio volumio[1185]: info: CoreStateMachine::pushState Apr 23 12:22:54 volumio volumio[1185]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 23 12:22:54 volumio volumio[1185]: info: CoreCommandRouter::volumioPushState Apr 23 12:22:54 volumio volumio[1185]: info: [LastFM] Current track has sufficient metadata: title (Green) and artist (Four Tet) passed on explicitly Apr 23 12:22:54 volumio volumio[1185]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 23 12:22:54 volumio volumio[1185]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"Green","url":"https://www.last.fm/music/Four+Tet/_/Green","duration":"228000","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"32683","playcount":"101900","artist":{"name":"Four Tet","mbid":"3bcff06f-675a-451f-9075-99e8657047e8","url":"https://www.last.fm/music/Four+Tet"},"album":{"artist":"Four Tet","title":"Sixteen Oceans","url":"https://www.last.fm/music/Four+Tet/Sixteen+Oceans","image":[{"#":"https://lastfm.freetls.fastly.net/i/u/34s/e95ee67ffd47387b3621b821785471fd.png","@":{"size":"small"}},{"#":"https://lastfm.freetls.fastly.net/i/u/64s/e95ee67ffd47387b3621b821785471fd.png","@":{"size":"medium"}},{"#":"https://lastfm.freetls.fastly.net/i/u/174s/e95ee67ffd47387b3621b821785471fd.png","@":{"size":"large"}},{"#":"https://lastfm.freetls.fastly.net/i/u/300x300/e95ee67ffd47387b3621b821785471fd.png","@":{"size":"extralarge"}}]},"userplaycount":"1","userloved":"0","toptags":{"tag":[{"name":"electronic","url":"https://www.last.fm/tag/electronic"},{"name":"ambient","url":"https://www.last.fm/tag/ambient"}]}}} Apr 23 12:22:54 volumio volumio[1185]: SPOTIFY: PUSH STATE SPOTIFY Apr 23 12:22:54 volumio volumio[1185]: SPOTIFY: {"status":"play","service":"spop","title":"Green","artist":"Four Tet","album":"Sixteen Oceans","albumart":"https://i.scdn.co/image/ab67616d00001e02210e19d835bb0af6620256cf","uri":"spotify:track:4EcQ8GHyJGLw45jkA9SzmD","trackType":"spotify","seek":0,"duration":228,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Apr 23 12:22:54 volumio volumio[1185]: info: CoreCommandRouter::servicePushState Apr 23 12:22:54 volumio volumio[1185]: info: CoreStateMachine::pushState Apr 23 12:22:54 volumio volumio[1185]: info: CoreCommandRouter::volumioPushState Apr 23 12:22:54 volumio volumio[1185]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 23 12:22:58 volumio volumio[1185]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 23 12:22:58 volumio volumio[1185]: Error: connect ETIMEDOUT 130.211.19.189:80 Apr 23 12:22:58 volumio volumio[1185]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Apr 23 12:22:58 volumio volumio[1185]: errno: -110, Apr 23 12:22:58 volumio volumio[1185]: code: 'ETIMEDOUT', Apr 23 12:22:58 volumio volumio[1185]: syscall: 'connect', Apr 23 12:22:58 volumio volumio[1185]: address: '130.211.19.189', Apr 23 12:22:58 volumio volumio[1185]: port: 80 Apr 23 12:22:58 volumio volumio[1185]: } Apr 23 12:22:58 volumio volumio[1185]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 23 12:22:59 volumio sudo[12152]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-23 12:21 Apr 23 12:22:59 volumio sudo[12152]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 11:42:54 AM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4049a67f1c09d4a94e033ba35a80a144"