Feb 18 10:29:02 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:02+01:00" level=debug msg="handling seek_to player command from 8dde45de0fc83d547c68343159241218981ab388"
Feb 18 10:29:02 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:02+01:00" level=debug msg="seek track to 138125ms"
Feb 18 10:29:02 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:02+01:00" level=debug msg="fetched chunk 11/18, size: 524288" uri="spotify:track:0asVHUy0gUckPzXVf7vj8b"
Feb 18 10:29:02 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:02+01:00" level=trace msg="seek to 138125ms (diff: 41ms, samples: 6091312, bytes: 6033045)" uri="spotify:track:0asVHUy0gUckPzXVf7vj8b"
Feb 18 10:29:03 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:03+01:00" level=debug msg="fetched chunk 12/18, size: 524288" uri="spotify:track:0asVHUy0gUckPzXVf7vj8b"
Feb 18 10:29:03 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:03+01:00" level=debug msg="fetched chunk 13/18, size: 524288" uri="spotify:track:0asVHUy0gUckPzXVf7vj8b"
Feb 18 10:29:03 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:03+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 18 10:29:03 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:03+01:00" level=trace msg="scheduling prefetch in 50s"
Feb 18 10:29:03 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:03+01:00" level=trace msg="emitting websocket event: seek"
Feb 18 10:29:03 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:03+01:00" level=debug msg="sending successful reply for dealer request"
Feb 18 10:29:03 volumio-260211 volumio[1193]: SPOTIFY: received: {"type":"seek","data":{"context_uri":"spotify:playlist:5Zu6xk7IwA4sIMvSie8efK","uri":"spotify:track:0asVHUy0gUckPzXVf7vj8b","position":138125,"duration":218797,"play_origin":"playlist"}}
Feb 18 10:29:03 volumio-260211 volumio[1193]: SPOTIFY: PUSH STATE SPOTIFY
Feb 18 10:29:03 volumio-260211 volumio[1193]: SPOTIFY: {"status":"play","service":"spop","title":"Love, Devotion & Surrender","artist":"Santana","album":"Welcome","albumart":"https://i.scdn.co/image/ab67616d00001e026a0201e4f3a8c49143e42de0","uri":"spotify:track:0asVHUy0gUckPzXVf7vj8b","trackType":"spotify","seek":138125,"duration":218,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"}
Feb 18 10:29:03 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:29:03 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:29:03 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 10:29:03 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:29:03 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:03+01:00" level=debug msg="fetched chunk 14/18, size: 524288" uri="spotify:track:0asVHUy0gUckPzXVf7vj8b"
Feb 18 10:29:05 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:05+01:00" level=debug msg="handling seek_to player command from 8dde45de0fc83d547c68343159241218981ab388"
Feb 18 10:29:05 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:05+01:00" level=debug msg="seek track to 156620ms"
Feb 18 10:29:05 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:05+01:00" level=trace msg="seek to 156620ms (diff: 225ms, samples: 6906942, bytes: 6726223)" uri="spotify:track:0asVHUy0gUckPzXVf7vj8b"
Feb 18 10:29:05 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:05+01:00" level=debug msg="fetched chunk 15/18, size: 524288" uri="spotify:track:0asVHUy0gUckPzXVf7vj8b"
Feb 18 10:29:05 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:05+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 18 10:29:05 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:05+01:00" level=trace msg="scheduling prefetch in 32s"
Feb 18 10:29:05 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:05+01:00" level=trace msg="emitting websocket event: seek"
Feb 18 10:29:05 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:05+01:00" level=debug msg="sending successful reply for dealer request"
Feb 18 10:29:05 volumio-260211 volumio[1193]: SPOTIFY: received: {"type":"seek","data":{"context_uri":"spotify:playlist:5Zu6xk7IwA4sIMvSie8efK","uri":"spotify:track:0asVHUy0gUckPzXVf7vj8b","position":156620,"duration":218797,"play_origin":"playlist"}}
Feb 18 10:29:05 volumio-260211 volumio[1193]: SPOTIFY: PUSH STATE SPOTIFY
Feb 18 10:29:05 volumio-260211 volumio[1193]: SPOTIFY: {"status":"play","service":"spop","title":"Love, Devotion & Surrender","artist":"Santana","album":"Welcome","albumart":"https://i.scdn.co/image/ab67616d00001e026a0201e4f3a8c49143e42de0","uri":"spotify:track:0asVHUy0gUckPzXVf7vj8b","trackType":"spotify","seek":156620,"duration":218,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"}
Feb 18 10:29:05 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:29:05 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:29:05 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 10:29:05 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:29:07 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:07+01:00" level=debug msg="fetched chunk 16/18, size: 524288" uri="spotify:track:0asVHUy0gUckPzXVf7vj8b"
Feb 18 10:29:15 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:15+01:00" level=debug msg="handling play player command from 8dde45de0fc83d547c68343159241218981ab388"
Feb 18 10:29:15 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:15+01:00" level=debug msg="resolved context of track" uri="spotify:playlist:5Zu6xk7IwA4sIMvSie8efK"
Feb 18 10:29:15 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:15+01:00" level=trace msg="fetched new page 0 with 719 items (list: 719)" uri="spotify:playlist:5Zu6xk7IwA4sIMvSie8efK"
Feb 18 10:29:15 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:15+01:00" level=debug msg="shuffled context with seed 2383934568544121194 (len: 719, keep: 187)" uri="spotify:playlist:5Zu6xk7IwA4sIMvSie8efK"
Feb 18 10:29:15 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:15+01:00" level=debug msg="loading track (paused: false, position: 3ms)" uri="spotify:track:0QSMnEFjzN0FuvyNjaHnCH"
Feb 18 10:29:15 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:15+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 18 10:29:15 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:15+01:00" level=trace msg="emitting websocket event: will_play"
Feb 18 10:29:15 volumio-260211 volumio[1193]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:5Zu6xk7IwA4sIMvSie8efK","uri":"spotify:track:0QSMnEFjzN0FuvyNjaHnCH","play_origin":"playlist"}}
Feb 18 10:29:15 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:15+01:00" level=debug msg="selected format OGG_VORBIS_320 (c9dcebd9c353d20413e8365c670ad6ae878e239a)" uri="spotify:track:0QSMnEFjzN0FuvyNjaHnCH"
Feb 18 10:29:15 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:15+01:00" level=debug msg="requested aes key for file c9dcebd9c353d20413e8365c670ad6ae878e239a, gid: 0QSMnEFjzN0FuvyNjaHnCH"
Feb 18 10:29:15 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:15+01:00" level=trace msg="found 2 cdn urls" uri="spotify:track:0QSMnEFjzN0FuvyNjaHnCH"
Feb 18 10:29:16 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:16+01:00" level=debug msg="fetched first chunk of 13, total size is 6429916 bytes" uri="spotify:track:0QSMnEFjzN0FuvyNjaHnCH"
Feb 18 10:29:16 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:16+01:00" level=trace msg="seek to 3ms (diff: 3ms, samples: 132, bytes: 0)" uri="spotify:track:0QSMnEFjzN0FuvyNjaHnCH"
Feb 18 10:29:16 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:16+01:00" level=info msg="loaded track \"Steppin' Razor\" (paused: false, position: 3ms, duration: 145066ms, prefetched: false)" uri="spotify:track:0QSMnEFjzN0FuvyNjaHnCH"
Feb 18 10:29:16 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:16+01:00" level=debug msg="fetched chunk 1/12, size: 524288" uri="spotify:track:0QSMnEFjzN0FuvyNjaHnCH"
Feb 18 10:29:16 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:16+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 18 10:29:16 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:16+01:00" level=trace msg="scheduling prefetch in 115s"
Feb 18 10:29:16 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:16+01:00" level=trace msg="emitting websocket event: metadata"
Feb 18 10:29:16 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:16+01:00" level=debug msg="sending successful reply for dealer request"
Feb 18 10:29:16 volumio-260211 volumio[1193]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:0QSMnEFjzN0FuvyNjaHnCH","name":"Steppin' Razor","artist_names":["Sublime"],"album_name":"Robbin' The Hood","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02ffa592514435c93fc05cba5b","position":3,"duration":145066,"release_date":"year:1994 month:3 day:1","track_number":5,"disc_number":1}}
Feb 18 10:29:16 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:16+01:00" level=debug msg="fetched chunk 2/12, size: 524288" uri="spotify:track:0QSMnEFjzN0FuvyNjaHnCH"
Feb 18 10:29:16 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:16+01:00" level=debug msg="fetched chunk 3/12, size: 524288" uri="spotify:track:0QSMnEFjzN0FuvyNjaHnCH"
Feb 18 10:29:16 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:16+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 18 10:29:16 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:16+01:00" level=trace msg="emitting websocket event: playing"
Feb 18 10:29:16 volumio-260211 volumio[1193]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:5Zu6xk7IwA4sIMvSie8efK","uri":"spotify:track:0QSMnEFjzN0FuvyNjaHnCH","resume":false,"play_origin":"playlist"}}
Feb 18 10:29:16 volumio-260211 volumio[1193]: SPOTIFY: PUSH STATE SPOTIFY
Feb 18 10:29:16 volumio-260211 volumio[1193]: SPOTIFY: {"status":"play","service":"spop","title":"Steppin' Razor","artist":"Sublime","album":"Robbin' The Hood","albumart":"https://i.scdn.co/image/ab67616d00001e02ffa592514435c93fc05cba5b","uri":"spotify:track:0QSMnEFjzN0FuvyNjaHnCH","trackType":"spotify","seek":3,"duration":145,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"}
Feb 18 10:29:16 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:29:16 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:29:16 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 10:29:16 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:29:17 volumio-260211 volumio[1193]: SPOTIFY: PUSH STATE SPOTIFY
Feb 18 10:29:17 volumio-260211 volumio[1193]: SPOTIFY: {"status":"play","service":"spop","title":"Steppin' Razor","artist":"Sublime","album":"Robbin' The Hood","albumart":"https://i.scdn.co/image/ab67616d00001e02ffa592514435c93fc05cba5b","uri":"spotify:track:0QSMnEFjzN0FuvyNjaHnCH","trackType":"spotify","seek":3,"duration":145,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"}
Feb 18 10:29:17 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:29:17 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:29:17 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:29:19 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:19+01:00" level=debug msg="handling seek_to player command from 8dde45de0fc83d547c68343159241218981ab388"
Feb 18 10:29:19 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:19+01:00" level=debug msg="seek track to 52703ms"
Feb 18 10:29:19 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:19+01:00" level=debug msg="fetched chunk 4/12, size: 524288" uri="spotify:track:0QSMnEFjzN0FuvyNjaHnCH"
Feb 18 10:29:19 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:19+01:00" level=trace msg="seek to 52703ms (diff: 154ms, samples: 2324202, bytes: 2268613)" uri="spotify:track:0QSMnEFjzN0FuvyNjaHnCH"
Feb 18 10:29:20 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:20+01:00" level=debug msg="fetched chunk 5/12, size: 524288" uri="spotify:track:0QSMnEFjzN0FuvyNjaHnCH"
Feb 18 10:29:20 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:20+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 18 10:29:20 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:20+01:00" level=trace msg="scheduling prefetch in 62s"
Feb 18 10:29:20 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:20+01:00" level=trace msg="emitting websocket event: seek"
Feb 18 10:29:20 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:20+01:00" level=debug msg="sending successful reply for dealer request"
Feb 18 10:29:20 volumio-260211 volumio[1193]: SPOTIFY: received: {"type":"seek","data":{"context_uri":"spotify:playlist:5Zu6xk7IwA4sIMvSie8efK","uri":"spotify:track:0QSMnEFjzN0FuvyNjaHnCH","position":52703,"duration":145066,"play_origin":"playlist"}}
Feb 18 10:29:20 volumio-260211 volumio[1193]: SPOTIFY: PUSH STATE SPOTIFY
Feb 18 10:29:20 volumio-260211 volumio[1193]: SPOTIFY: {"status":"play","service":"spop","title":"Steppin' Razor","artist":"Sublime","album":"Robbin' The Hood","albumart":"https://i.scdn.co/image/ab67616d00001e02ffa592514435c93fc05cba5b","uri":"spotify:track:0QSMnEFjzN0FuvyNjaHnCH","trackType":"spotify","seek":52703,"duration":145,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"}
Feb 18 10:29:20 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:29:20 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:29:20 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 10:29:20 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:29:20 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:20+01:00" level=debug msg="fetched chunk 6/12, size: 524288" uri="spotify:track:0QSMnEFjzN0FuvyNjaHnCH"
Feb 18 10:29:20 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:20+01:00" level=debug msg="fetched chunk 7/12, size: 524288" uri="spotify:track:0QSMnEFjzN0FuvyNjaHnCH"
Feb 18 10:29:20 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:20+01:00" level=trace msg="received accesspoint ping"
Feb 18 10:29:20 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:20+01:00" level=trace msg="received accesspoint pong ack"
Feb 18 10:29:21 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:21+01:00" level=trace msg="sent dealer ping"
Feb 18 10:29:21 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:21+01:00" level=trace msg="received dealer pong"
Feb 18 10:29:28 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:28+01:00" level=debug msg="fetched chunk 8/12, size: 524288" uri="spotify:track:0QSMnEFjzN0FuvyNjaHnCH"
Feb 18 10:29:39 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:39+01:00" level=debug msg="handling pause player command from 8dde45de0fc83d547c68343159241218981ab388"
Feb 18 10:29:39 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:39+01:00" level=debug msg="pause track at 72114ms"
Feb 18 10:29:39 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:39+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 18 10:29:39 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:39+01:00" level=debug msg="sending successful reply for dealer request"
Feb 18 10:29:39 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:39+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 18 10:29:39 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:39+01:00" level=trace msg="emitting websocket event: paused"
Feb 18 10:29:39 volumio-260211 volumio[1193]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:playlist:5Zu6xk7IwA4sIMvSie8efK","uri":"spotify:track:0QSMnEFjzN0FuvyNjaHnCH","play_origin":"playlist"}}
Feb 18 10:29:39 volumio-260211 volumio[1193]: SPOTIFY: PUSH STATE SPOTIFY
Feb 18 10:29:39 volumio-260211 volumio[1193]: SPOTIFY: {"status":"pause","service":"spop","title":"Steppin' Razor","artist":"Sublime","album":"Robbin' The Hood","albumart":"https://i.scdn.co/image/ab67616d00001e02ffa592514435c93fc05cba5b","uri":"spotify:track:0QSMnEFjzN0FuvyNjaHnCH","trackType":"spotify","seek":71703,"duration":145,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"}
Feb 18 10:29:39 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:29:39 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:29:39 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 10:29:39 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:29:51 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:51+01:00" level=trace msg="sent dealer ping"
Feb 18 10:29:51 volumio-260211 go-librespot[1724]: time="2026-02-18T10:29:51+01:00" level=trace msg="received dealer pong"
Feb 18 10:29:55 volumio-260211 kernel: hwmon hwmon1: Voltage normalised
Feb 18 10:29:56 volumio-260211 sudo[17698]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 18 10:29:56 volumio-260211 sudo[17696]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 18 10:29:56 volumio-260211 sudo[17698]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 10:29:56 volumio-260211 sudo[17696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 10:29:56 volumio-260211 sudo[17698]: pam_unix(sudo:session): session closed for user root
Feb 18 10:29:56 volumio-260211 sudo[17696]: pam_unix(sudo:session): session closed for user root
Feb 18 10:29:57 volumio-260211 volumio[1193]: verbose: New Socket.io Connection to 192.168.0.92 from 192.168.0.55 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/145.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioGetVisibleSources
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioGetState
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Feb 18 10:29:57 volumio-260211 kernel: hwmon hwmon1: Undervoltage detected!
Feb 18 10:29:57 volumio-260211 sudo[17705]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 18 10:29:57 volumio-260211 sudo[17705]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 10:29:57 volumio-260211 sudo[17705]: pam_unix(sudo:session): session closed for user root
Feb 18 10:29:57 volumio-260211 sudo[17707]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 18 10:29:57 volumio-260211 sudo[17707]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 18 10:29:57 volumio-260211 sudo[17707]: pam_unix(sudo:session): session closed for user root
Feb 18 10:29:57 volumio-260211 volumio[1193]: verbose: New Socket.io Connection to 192.168.0.92 from 192.168.0.55 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/145.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioGetState
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioGetVisibleSources
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: Listing playlists
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Feb 18 10:29:57 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Feb 18 10:30:00 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Feb 18 10:30:00 volumio-260211 volumio[1193]: info: Received Get System Info
Feb 18 10:30:00 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Feb 18 10:30:00 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Feb 18 10:30:00 volumio-260211 volumio[1193]: info: Discovery: Getting this device information
Feb 18 10:30:00 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioGetState
Feb 18 10:30:00 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Feb 18 10:30:00 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Feb 18 10:30:03 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: 80s80s , handleBrowseUri
Feb 18 10:30:03 volumio-260211 volumio[1193]: info: [1771407003058] [80s80s] handleBrowseUri curUri: 80s80s
Feb 18 10:30:03 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioGetQueue
Feb 18 10:30:03 volumio-260211 volumio[1193]: info: CoreStateMachine::getQueue
Feb 18 10:30:03 volumio-260211 volumio[1193]: info: CorePlayQueue::getQueue
Feb 18 10:30:03 volumio-260211 volumio[1193]: info: Preload queue cleared
Feb 18 10:30:03 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Feb 18 10:30:03 volumio-260211 volumio[1193]: info: Received Get System Info
Feb 18 10:30:03 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Feb 18 10:30:03 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Feb 18 10:30:03 volumio-260211 volumio[1193]: info: Discovery: Getting this device information
Feb 18 10:30:03 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioGetState
Feb 18 10:30:03 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: Preload queue cleared
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioReplaceandPlayItems
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreStateMachine::ClearQueue
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreStateMachine::stop
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreStateMachine::serviceStop
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreCommandRouter::serviceStop
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: Spotify Stop
Feb 18 10:30:05 volumio-260211 volumio[1193]: SPOTIFY: SPOTIFY STOP
Feb 18 10:30:05 volumio-260211 volumio[1193]: SPOTIFY: {"status":"pause","title":"Steppin' Razor","artist":"Sublime","album":"Robbin' The Hood","albumart":"https://i.scdn.co/image/ab67616d00001e02ffa592514435c93fc05cba5b","uri":"spotify:track:0QSMnEFjzN0FuvyNjaHnCH","trackType":"spotify","codec":"ogg","seek":71703,"duration":145,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":true,"stream":false,"updatedb":false,"volatile":true,"service":"spop"}
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: Sending Spotify command to local API: /player/pause
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CorePlayQueue::clearPlayQueue
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CorePlayQueue::saveQueue
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushQueue
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreStateMachine::addQueueItems
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CorePlayQueue::addQueueItems
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: Preload queue cleared
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: Adding Item to queue: 80s80s/nineties
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: Exploding uri 80s80s/nineties in service 80s80s
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: [1771407005798] [80s80s] explodeUri: 80s80s/nineties
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushQueue
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CorePlayQueue::saveQueue
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreStateMachine::updateTrackBlock
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrackBlock
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPlay
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreStateMachine::play index 0
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreStateMachine::setConsumeUpdateService undefined
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreStateMachine::stop
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreStateMachine::setConsumeUpdateService undefined
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreStateMachine::updateTrackBlock
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrackBlock
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreStateMachine::stPlaybackTimer
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreStateMachine::serviceStop
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: ControllerMpd::stop
Feb 18 10:30:05 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand stop
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: sendMpdCommand stop took 19 milliseconds
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreStateMachine::play index undefined
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CoreStateMachine::setConsumeUpdateService undefined
Feb 18 10:30:05 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:05 volumio-260211 go-librespot[1724]: time="2026-02-18T10:30:05+01:00" level=debug msg="pause track at 72566ms"
Feb 18 10:30:06 volumio-260211 go-librespot[1724]: time="2026-02-18T10:30:06+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 18 10:30:06 volumio-260211 go-librespot[1724]: time="2026-02-18T10:30:06+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 18 10:30:06 volumio-260211 go-librespot[1724]: time="2026-02-18T10:30:06+01:00" level=trace msg="emitting websocket event: paused"
Feb 18 10:30:06 volumio-260211 volumio[1193]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:playlist:5Zu6xk7IwA4sIMvSie8efK","uri":"spotify:track:0QSMnEFjzN0FuvyNjaHnCH","play_origin":"playlist"}}
Feb 18 10:30:06 volumio-260211 volumio[1193]: info: Spotify is playing in volatile mode
Feb 18 10:30:06 volumio-260211 volumio[1193]: info: CoreStateMachine::setConsumeUpdateService undefined
Feb 18 10:30:06 volumio-260211 volumio[1193]: SPOTIFY: UNSET VOLATILE
Feb 18 10:30:06 volumio-260211 volumio[1193]: 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":true,"random":true,"repeat":true,"repeatSingle":false,"updatedb":false,"consume":false}
Feb 18 10:30:06 volumio-260211 volumio[1193]: SPOTIFY: PUSH STATE SPOTIFY
Feb 18 10:30:06 volumio-260211 volumio[1193]: SPOTIFY: {"status":"pause","service":"spop","title":"Steppin' Razor","artist":"Sublime","album":"Robbin' The Hood","albumart":"https://i.scdn.co/image/ab67616d00001e02ffa592514435c93fc05cba5b","uri":"spotify:track:0QSMnEFjzN0FuvyNjaHnCH","trackType":"spotify","seek":71703,"duration":145,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"}
Feb 18 10:30:06 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:30:06 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:06 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 10:30:06 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:08 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: 80s80s , handleBrowseUri
Feb 18 10:30:08 volumio-260211 volumio[1193]: info: [1771407008795] [80s80s] handleBrowseUri curUri: 80s80s/nineties
Feb 18 10:30:08 volumio-260211 volumio[1193]: info: [1771407008796] [80s80s] getRadioContent url: nineties
Feb 18 10:30:08 volumio-260211 volumio[1193]: info: Preload queue cleared
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Preload queue cleared
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioReplaceandPlayItems
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::ClearQueue
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::stop
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::serviceStop
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::serviceStop
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Spotify Stop
Feb 18 10:30:11 volumio-260211 volumio[1193]: SPOTIFY: SPOTIFY STOP
Feb 18 10:30:11 volumio-260211 volumio[1193]: SPOTIFY: {"status":"pause","title":"Steppin' Razor","artist":"Sublime","album":"Robbin' The Hood","albumart":"https://i.scdn.co/image/ab67616d00001e02ffa592514435c93fc05cba5b","uri":"spotify:track:0QSMnEFjzN0FuvyNjaHnCH","trackType":"spotify","codec":"ogg","seek":71703,"duration":145,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":100,"dbVolume":null,"mute":false,"disableVolumeControl":true,"stream":false,"updatedb":false,"volatile":true,"service":"spop"}
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Sending Spotify command to local API: /player/pause
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::clearPlayQueue
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::saveQueue
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushQueue
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::addQueueItems
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::addQueueItems
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Preload queue cleared
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Adding Item to queue: webnineties/0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Exploding uri webnineties/0 in service 80s80s
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: [1771407011377] [80s80s] explodeUri: webnineties/0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushQueue
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::saveQueue
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::updateTrackBlock
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrackBlock
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPlay
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::play index 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::setConsumeUpdateService undefined
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::stop
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::setConsumeUpdateService undefined
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::updateTrackBlock
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrackBlock
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::stPlaybackTimer
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::serviceStop
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::serviceStop
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: ControllerMpd::stop
Feb 18 10:30:11 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand stop
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: sendMpdCommand stop took 24 milliseconds
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: verbose: STATE SERVICE {"status":"stop"}
Feb 18 10:30:11 volumio-260211 volumio[1193]: verbose: CURRENT POSITION 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::syncState stateService stop
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::syncState currentStatus stop
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: No code
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::play index undefined
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::setConsumeUpdateService undefined
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::startPlaybackTimer
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: [1771407011469] [80s80s] clearAddPlayTrack url: http://streams.90s90s.de/pop/mp3-192/volumio
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: [1771407011471] [80s80s] getContentOfUrl started with url http://iris-90s90s.loverad.io/flow.json?station=141&count=2
Feb 18 10:30:11 volumio-260211 go-librespot[1724]: time="2026-02-18T10:30:11+01:00" level=debug msg="pause track at 72566ms"
Feb 18 10:30:11 volumio-260211 go-librespot[1724]: time="2026-02-18T10:30:11+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: [1771407011703] [80s80s] received new event containing 2 songs.
Feb 18 10:30:11 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand stop
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: sendMpdCommand stop took 9 milliseconds
Feb 18 10:30:11 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand clear
Feb 18 10:30:11 volumio-260211 volumio[1193]: info:
Feb 18 10:30:11 volumio-260211 volumio[1193]: ---------------------------- MPD announces system playlist update
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Ignoring MPD Status Update
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: sendMpdCommand clear took 7 milliseconds
Feb 18 10:30:11 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand consume 1
Feb 18 10:30:11 volumio-260211 volumio[1193]: info:
Feb 18 10:30:11 volumio-260211 volumio[1193]: ---------------------------- MPD announces system playlist update
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Ignoring MPD Status Update
Feb 18 10:30:11 volumio-260211 volumio[1193]: info:
Feb 18 10:30:11 volumio-260211 volumio[1193]: ---------------------------- MPD announces system playlist update
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Ignoring MPD Status Update
Feb 18 10:30:11 volumio-260211 volumio[1193]: error: updateQueue error: null
Feb 18 10:30:11 volumio-260211 volumio[1193]: info:
Feb 18 10:30:11 volumio-260211 volumio[1193]: ---------------------------- MPD announces state update: options
Feb 18 10:30:11 volumio-260211 volumio[1193]: error: updateQueue error: null
Feb 18 10:30:11 volumio-260211 volumio[1193]: error: updateQueue error: null
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: ------------------------------ 18ms
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: sendMpdCommand consume 1 took 14 milliseconds
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: ControllerMpd::getState
Feb 18 10:30:11 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand status
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: ------------------------------ 14ms
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: ------------------------------ 11ms
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: [1771407011742] [80s80s] adding url: http://streams.90s90s.de/pop/mp3-192/volumio
Feb 18 10:30:11 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand add "http://streams.90s90s.de/pop/mp3-192/volumio"
Feb 18 10:30:11 volumio-260211 volumio[1193]: info:
Feb 18 10:30:11 volumio-260211 volumio[1193]: ---------------------------- MPD announces state update: options
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: ControllerMpd::getState
Feb 18 10:30:11 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand status
Feb 18 10:30:11 volumio-260211 volumio[1193]: info:
Feb 18 10:30:11 volumio-260211 volumio[1193]: ---------------------------- MPD announces state update: options
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: ControllerMpd::getState
Feb 18 10:30:11 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand status
Feb 18 10:30:11 volumio-260211 volumio[1193]: info:
Feb 18 10:30:11 volumio-260211 volumio[1193]: ---------------------------- MPD announces system playlist update
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Ignoring MPD Status Update
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: sendMpdCommand status took 14 milliseconds
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: sendMpdCommand add "http://streams.90s90s.de/pop/mp3-192/volumio" took 13 milliseconds
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: sendMpdCommand status took 11 milliseconds
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: sendMpdCommand status took 10 milliseconds
Feb 18 10:30:11 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseState
Feb 18 10:30:11 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand play
Feb 18 10:30:11 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseState
Feb 18 10:30:11 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: ControllerMpd::pushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: ControllerMpd::pushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: ControllerMpd::pushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current 80s80s Received mpd
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: ------------------------------ 69ms
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: ------------------------------ 71ms
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: ------------------------------ 70ms
Feb 18 10:30:11 volumio-260211 volumio[1193]: info:
Feb 18 10:30:11 volumio-260211 volumio[1193]: ---------------------------- MPD announces system playlist update
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Ignoring MPD Status Update
Feb 18 10:30:11 volumio-260211 volumio[1193]: info:
Feb 18 10:30:11 volumio-260211 volumio[1193]: ---------------------------- MPD announces system playlist update
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Ignoring MPD Status Update
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: ------------------------------ 79ms
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: sendMpdCommand play took 61 milliseconds
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: ------------------------------ 13ms
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: ------------------------------ 10ms
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: [1771407011835] [80s80s] Pushing the next song state: Dr. Alban - Sing Hallelujah!
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: verbose: STATE SERVICE {"status":"play","service":"80s80s","type":"track","trackType":"80s80s Radio","radioType":"80s80s","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music124/v4/b2/1c/18/b21c1864-f622-5fab-2335-5963ee45ce7c/source/600x600bb.jpg","name":"Dr. Alban - Sing Hallelujah!","title":"Sing Hallelujah!","artist":"90s90s Hits","album":"","streaming":true,"disableUiControls":true,"duration":"234","seek":0,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2}
Feb 18 10:30:11 volumio-260211 volumio[1193]: verbose: CURRENT POSITION 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::syncState stateService play
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::syncState currentStatus stop
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: [1771407011844] [80s80s] PlayNextTrack API delay: 30
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: [1771407011882] [80s80s] Setting timer to: 17156 milliseconds.
Feb 18 10:30:11 volumio-260211 go-librespot[1724]: time="2026-02-18T10:30:11+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 18 10:30:11 volumio-260211 go-librespot[1724]: time="2026-02-18T10:30:11+01:00" level=trace msg="emitting websocket event: paused"
Feb 18 10:30:11 volumio-260211 volumio[1193]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:playlist:5Zu6xk7IwA4sIMvSie8efK","uri":"spotify:track:0QSMnEFjzN0FuvyNjaHnCH","play_origin":"playlist"}}
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Spotify is playing in volatile mode
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::setConsumeUpdateService undefined
Feb 18 10:30:11 volumio-260211 volumio[1193]: SPOTIFY: UNSET VOLATILE
Feb 18 10:30:11 volumio-260211 volumio[1193]: SPOTIFY: {"status":"stop","position":0,"title":"90s90s Hits","albumart":"/albumart?sourceicon=music_service/80s80s/images/90s90s-hits-cover.png","uri":"http://streams.90s90s.de/pop/mp3-192/volumio","trackType":"80s80s Radio","seek":253,"duration":1000,"random":true,"repeat":true,"repeatSingle":false,"consume":false,"volume":100,"dbVolume":null,"disableVolumeControl":true,"mute":false,"stream":"80s80s Radio","volatile":false,"service":"80s80s"}
Feb 18 10:30:11 volumio-260211 volumio[1193]: SPOTIFY: PUSH STATE SPOTIFY
Feb 18 10:30:11 volumio-260211 volumio[1193]: SPOTIFY: {"status":"pause","service":"spop","title":"Steppin' Razor","artist":"Sublime","album":"Robbin' The Hood","albumart":"https://i.scdn.co/image/ab67616d00001e02ffa592514435c93fc05cba5b","uri":"spotify:track:0QSMnEFjzN0FuvyNjaHnCH","trackType":"spotify","seek":71703,"duration":145,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"}
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: CorePlayQueue::getTrack 0
Feb 18 10:30:11 volumio-260211 volumio[1193]: info: Prefetching next song
Feb 18 10:30:12 volumio-260211 volumio[1193]: info:
Feb 18 10:30:12 volumio-260211 volumio[1193]: ---------------------------- MPD announces state update: player
Feb 18 10:30:12 volumio-260211 volumio[1193]: info: ControllerMpd::getState
Feb 18 10:30:12 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand status
Feb 18 10:30:12 volumio-260211 volumio[1193]: info:
Feb 18 10:30:12 volumio-260211 volumio[1193]: ---------------------------- MPD announces state update: player
Feb 18 10:30:12 volumio-260211 volumio[1193]: info: ControllerMpd::getState
Feb 18 10:30:12 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand status
Feb 18 10:30:12 volumio-260211 volumio[1193]: info:
Feb 18 10:30:12 volumio-260211 volumio[1193]: ---------------------------- MPD announces state update: player
Feb 18 10:30:12 volumio-260211 volumio[1193]: info: ControllerMpd::getState
Feb 18 10:30:12 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand status
Feb 18 10:30:12 volumio-260211 volumio[1193]: info:
Feb 18 10:30:12 volumio-260211 volumio[1193]: ---------------------------- MPD announces state update: player
Feb 18 10:30:12 volumio-260211 volumio[1193]: info: sendMpdCommand status took 22 milliseconds
Feb 18 10:30:12 volumio-260211 volumio[1193]: info: ControllerMpd::getState
Feb 18 10:30:12 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand status
Feb 18 10:30:12 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseState
Feb 18 10:30:12 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Feb 18 10:30:12 volumio-260211 volumio[1193]: info:
Feb 18 10:30:12 volumio-260211 volumio[1193]: ---------------------------- MPD announces state update: player
Feb 18 10:30:12 volumio-260211 volumio[1193]: info: ControllerMpd::getState
Feb 18 10:30:12 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand status
Feb 18 10:30:12 volumio-260211 volumio[1193]: info: sendMpdCommand status took 29 milliseconds
Feb 18 10:30:12 volumio-260211 volumio[1193]: info: sendMpdCommand status took 27 milliseconds
Feb 18 10:30:12 volumio-260211 volumio[1193]: info: sendMpdCommand status took 9 milliseconds
Feb 18 10:30:12 volumio-260211 volumio[1193]: info: sendMpdCommand playlistinfo took 8 milliseconds
Feb 18 10:30:12 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseState
Feb 18 10:30:12 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Feb 18 10:30:12 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseState
Feb 18 10:30:12 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Feb 18 10:30:12 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseState
Feb 18 10:30:12 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Feb 18 10:30:12 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseTrackInfo
Feb 18 10:30:12 volumio-260211 volumio[1193]: info: ControllerMpd::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ------------------------------ 65ms
Feb 18 10:30:13 volumio-260211 volumio[1193]: info:
Feb 18 10:30:13 volumio-260211 volumio[1193]: ---------------------------- MPD announces state update: player
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ControllerMpd::getState
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand status
Feb 18 10:30:13 volumio-260211 volumio[1193]: info:
Feb 18 10:30:13 volumio-260211 volumio[1193]: ---------------------------- MPD announces system playlist update
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: Ignoring MPD Status Update
Feb 18 10:30:13 volumio-260211 volumio[1193]: info:
Feb 18 10:30:13 volumio-260211 volumio[1193]: ---------------------------- MPD announces state update: player
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ControllerMpd::getState
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand status
Feb 18 10:30:13 volumio-260211 volumio[1193]: info:
Feb 18 10:30:13 volumio-260211 volumio[1193]: ---------------------------- MPD announces system playlist update
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: Ignoring MPD Status Update
Feb 18 10:30:13 volumio-260211 volumio[1193]: info:
Feb 18 10:30:13 volumio-260211 volumio[1193]: ---------------------------- MPD announces state update: player
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: sendMpdCommand status took 46 milliseconds
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ControllerMpd::getState
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand status
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: sendMpdCommand playlistinfo took 42 milliseconds
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: sendMpdCommand playlistinfo took 42 milliseconds
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: sendMpdCommand playlistinfo took 42 milliseconds
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: sendMpdCommand status took 15 milliseconds
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ------------------------------ 13ms
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseState
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseTrackInfo
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseTrackInfo
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseTrackInfo
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseState
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ControllerMpd::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ControllerMpd::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ControllerMpd::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ------------------------------ 124ms
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ------------------------------ 123ms
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ------------------------------ 107ms
Feb 18 10:30:13 volumio-260211 volumio[1193]: info:
Feb 18 10:30:13 volumio-260211 volumio[1193]: ---------------------------- MPD announces system playlist update
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: Ignoring MPD Status Update
Feb 18 10:30:13 volumio-260211 volumio[1193]: info:
Feb 18 10:30:13 volumio-260211 volumio[1193]: ---------------------------- MPD announces state update: player
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ControllerMpd::getState
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand status
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: sendMpdCommand status took 85 milliseconds
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ------------------------------ 84ms
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: sendMpdCommand status took 92 milliseconds
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: sendMpdCommand playlistinfo took 89 milliseconds
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: sendMpdCommand playlistinfo took 86 milliseconds
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ------------------------------ 43ms
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: sendMpdCommand status took 41 milliseconds
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseState
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseState
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseTrackInfo
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseTrackInfo
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseState
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ControllerMpd::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ControllerMpd::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ------------------------------ 178ms
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ------------------------------ 145ms
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: sendMpdCommand playlistinfo took 36 milliseconds
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: sendMpdCommand playlistinfo took 36 milliseconds
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: sendMpdCommand playlistinfo took 32 milliseconds
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseTrackInfo
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseTrackInfo
Feb 18 10:30:13 volumio-260211 volumio[1193]: verbose: ControllerMpd::parseTrackInfo
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ControllerMpd::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ControllerMpd::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ControllerMpd::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::servicePushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreStateMachine::pushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioPushState
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ------------------------------ 174ms
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ------------------------------ 172ms
Feb 18 10:30:13 volumio-260211 volumio[1193]: info: ------------------------------ 117ms
Feb 18 10:30:16 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Feb 18 10:30:16 volumio-260211 volumio[1193]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Feb 18 10:30:16 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Feb 18 10:30:16 volumio-260211 volumio[1193]: info: Received Get System Version
Feb 18 10:30:16 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 18 10:30:16 volumio-260211 volumio[1193]: info: Received Get System Info
Feb 18 10:30:16 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Feb 18 10:30:16 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Feb 18 10:30:16 volumio-260211 volumio[1193]: info: Discovery: Getting this device information
Feb 18 10:30:16 volumio-260211 volumio[1193]: info: CoreCommandRouter::volumioGetState
Feb 18 10:30:16 volumio-260211 volumio[1193]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Feb 18 10:30:21 volumio-260211 go-librespot[1724]: time="2026-02-18T10:30:21+01:00" level=trace msg="sent dealer ping"
Feb 18 10:30:21 volumio-260211 go-librespot[1724]: time="2026-02-18T10:30:21+01:00" level=trace msg="received dealer pong"
Feb 18 10:30:29 volumio-260211 volumio[1193]: info: [1771407029043] [80s80s] Pushing the next song state Dr. Alban - Sing Hallelujah! and getting next track.
Feb 18 10:30:29 volumio-260211 volumio[1193]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 18 10:30:29 volumio-260211 volumio[1193]: TypeError: Cannot set properties of undefined (setting 'name')
Feb 18 10:30:29 volumio-260211 volumio[1193]: at Controller80s80s.pushSongState (/data/plugins/music_service/80s80s/index.js:565:20)
Feb 18 10:30:29 volumio-260211 volumio[1193]: at Controller80s80s.playNextTrack (/data/plugins/music_service/80s80s/index.js:665:34)
Feb 18 10:30:29 volumio-260211 volumio[1193]: at NanoTimer.setTimeout (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:343:9)
Feb 18 10:30:29 volumio-260211 volumio[1193]: at Immediate. (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:327:66)
Feb 18 10:30:29 volumio-260211 volumio[1193]: at process.processImmediate (node:internal/timers:478:21)
Feb 18 10:30:29 volumio-260211 volumio[1193]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 18 10:30:30 volumio-260211 sudo[17826]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 10:29'
Feb 18 10:30:30 volumio-260211 sudo[17826]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="a78d359cf1dc63ac74e9d151015afd30d31a709a"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="c1ffe93b2136013fc1b5903a4ed7e3f34e0a7bec"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu Feb 5 14:07:07 UTC 2026"
VOLUMIO_VERSION="4.096"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="5e37060f9823263a753eb5e84030104f"