Feb 11 06:28:00 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5066.
Feb 11 06:28:00 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Feb 11 06:28:00 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Feb 11 06:28:00 volumio upmpdcli[26197]: Could not open config: /tmp/upmpdcli.conf
Feb 11 06:28:00 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 06:28:00 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Feb 11 06:28:04 volumio go-librespot[1686]: time="2026-02-11T06:28:04-07:00" level=debug msg="fetched chunk 4/4, size: 49232" uri="spotify:track:152QVnhbR0zcq3e5NM4U7t"
Feb 11 06:28:10 volumio go-librespot[1686]: time="2026-02-11T06:28:10-07:00" level=trace msg="received accesspoint ping"
Feb 11 06:28:10 volumio go-librespot[1686]: time="2026-02-11T06:28:10-07:00" level=trace msg="received accesspoint pong ack"
Feb 11 06:28:10 volumio go-librespot[1686]: time="2026-02-11T06:28:10-07:00" level=trace msg="sent dealer ping"
Feb 11 06:28:10 volumio go-librespot[1686]: time="2026-02-11T06:28:10-07:00" level=trace msg="received dealer pong"
Feb 11 06:28:15 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5067.
Feb 11 06:28:15 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Feb 11 06:28:15 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Feb 11 06:28:15 volumio upmpdcli[26213]: Could not open config: /tmp/upmpdcli.conf
Feb 11 06:28:15 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 06:28:15 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Feb 11 06:28:20 volumio go-librespot[1686]: time="2026-02-11T06:28:20-07:00" level=debug msg="prefetching next track" uri="spotify:track:2t0LK6NCvQKdJuyI3qgkra"
Feb 11 06:28:20 volumio go-librespot[1686]: time="2026-02-11T06:28:20-07:00" level=debug msg="selected format OGG_VORBIS_320 (6595df224d65ed18e2a30bd6090dbd2fa4873639)" uri="spotify:track:2t0LK6NCvQKdJuyI3qgkra"
Feb 11 06:28:20 volumio go-librespot[1686]: time="2026-02-11T06:28:20-07:00" level=debug msg="requested aes key for file 6595df224d65ed18e2a30bd6090dbd2fa4873639, gid: 2t0LK6NCvQKdJuyI3qgkra"
Feb 11 06:28:21 volumio go-librespot[1686]: time="2026-02-11T06:28:21-07:00" level=trace msg="found 2 cdn urls" uri="spotify:track:2t0LK6NCvQKdJuyI3qgkra"
Feb 11 06:28:21 volumio go-librespot[1686]: time="2026-02-11T06:28:21-07:00" level=debug msg="fetched first chunk of 5, total size is 2132796 bytes" uri="spotify:track:2t0LK6NCvQKdJuyI3qgkra"
Feb 11 06:28:21 volumio go-librespot[1686]: time="2026-02-11T06:28:21-07:00" level=info msg="prefetched track \"Serene Night - Ambient Piano Version\" (duration: 60576ms)" uri="spotify:track:2t0LK6NCvQKdJuyI3qgkra"
Feb 11 06:28:21 volumio go-librespot[1686]: time="2026-02-11T06:28:21-07:00" level=debug msg="fetched chunk 1/4, size: 524288" uri="spotify:track:2t0LK6NCvQKdJuyI3qgkra"
Feb 11 06:28:21 volumio go-librespot[1686]: time="2026-02-11T06:28:21-07:00" level=debug msg="fetched chunk 2/4, size: 524288" uri="spotify:track:2t0LK6NCvQKdJuyI3qgkra"
Feb 11 06:28:21 volumio go-librespot[1686]: time="2026-02-11T06:28:21-07:00" level=debug msg="fetched chunk 3/4, size: 524288" uri="spotify:track:2t0LK6NCvQKdJuyI3qgkra"
Feb 11 06:28:30 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5068.
Feb 11 06:28:30 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Feb 11 06:28:30 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Feb 11 06:28:30 volumio upmpdcli[26243]: Could not open config: /tmp/upmpdcli.conf
Feb 11 06:28:30 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 06:28:30 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Feb 11 06:28:40 volumio go-librespot[1686]: time="2026-02-11T06:28:40-07:00" level=trace msg="sent dealer ping"
Feb 11 06:28:40 volumio go-librespot[1686]: time="2026-02-11T06:28:40-07:00" level=trace msg="received dealer pong"
Feb 11 06:28:45 volumio systemd[1]: upmpdcli.service: Scheduled restart job, restart counter is at 5069.
Feb 11 06:28:45 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Feb 11 06:28:46 volumio systemd[1]: Started upmpdcli.service - UPnP Renderer front-end to MPD.
Feb 11 06:28:46 volumio upmpdcli[26259]: Could not open config: /tmp/upmpdcli.conf
Feb 11 06:28:46 volumio systemd[1]: upmpdcli.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 06:28:46 volumio systemd[1]: upmpdcli.service: Failed with result 'exit-code'.
Feb 11 06:28:50 volumio go-librespot[1686]: time="2026-02-11T06:28:50-07:00" level=trace msg="emitting websocket event: not_playing"
Feb 11 06:28:50 volumio go-librespot[1686]: time="2026-02-11T06:28:50-07:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:2t0LK6NCvQKdJuyI3qgkra"
Feb 11 06:28:50 volumio volumio[1142]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:playlist:4JSSPYKaE9sP3qqlkCIEGi","uri":"spotify:track:152QVnhbR0zcq3e5NM4U7t","play_origin":"playlist/ondemand"}}
Feb 11 06:28:50 volumio volumio[1142]: error: Failed to decode event: not_playing
Feb 11 06:28:50 volumio go-librespot[1686]: time="2026-02-11T06:28:50-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 06:28:50 volumio go-librespot[1686]: time="2026-02-11T06:28:50-07:00" level=trace msg="emitting websocket event: will_play"
Feb 11 06:28:50 volumio go-librespot[1686]: time="2026-02-11T06:28:50-07:00" level=info msg="loaded track \"Serene Night - Ambient Piano Version\" (paused: false, position: 0ms, duration: 60576ms, prefetched: true)" uri="spotify:track:2t0LK6NCvQKdJuyI3qgkra"
Feb 11 06:28:50 volumio volumio[1142]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:playlist:4JSSPYKaE9sP3qqlkCIEGi","uri":"spotify:track:2t0LK6NCvQKdJuyI3qgkra","play_origin":"playlist/ondemand"}}
Feb 11 06:28:50 volumio go-librespot[1686]: time="2026-02-11T06:28:50-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 06:28:50 volumio go-librespot[1686]: time="2026-02-11T06:28:50-07:00" level=trace msg="scheduling prefetch in 31s"
Feb 11 06:28:50 volumio go-librespot[1686]: time="2026-02-11T06:28:50-07:00" level=trace msg="emitting websocket event: metadata"
Feb 11 06:28:50 volumio go-librespot[1686]: time="2026-02-11T06:28:50-07:00" level=debug msg="handling set_options player command from social-connect-ae11c7dcdc8f10497051b7fd29ba3d5b"
Feb 11 06:28:50 volumio go-librespot[1686]: time="2026-02-11T06:28:50-07:00" level=debug msg="sending successful reply for dealer request"
Feb 11 06:28:50 volumio volumio[1142]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2t0LK6NCvQKdJuyI3qgkra","name":"Serene Night - Ambient Piano Version","artist_names":["July Sunrise"],"album_name":"Serene Night (Ambient Piano Version)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02cd6cfeb6f3b78edeb840fcdd","position":0,"duration":60576,"release_date":"year:2025 month:9 day:29","track_number":1,"disc_number":1}}
Feb 11 06:28:50 volumio go-librespot[1686]: time="2026-02-11T06:28:50-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Feb 11 06:28:50 volumio go-librespot[1686]: time="2026-02-11T06:28:50-07:00" level=trace msg="emitting websocket event: playing"
Feb 11 06:28:50 volumio go-librespot[1686]: time="2026-02-11T06:28:50-07:00" level=debug msg="handling set_options player command from social-connect-ae11c7dcdc8f10497051b7fd29ba3d5b"
Feb 11 06:28:50 volumio go-librespot[1686]: time="2026-02-11T06:28:50-07:00" level=debug msg="sending successful reply for dealer request"
Feb 11 06:28:50 volumio volumio[1142]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:playlist:4JSSPYKaE9sP3qqlkCIEGi","uri":"spotify:track:2t0LK6NCvQKdJuyI3qgkra","resume":false,"play_origin":"playlist/ondemand"}}
Feb 11 06:28:50 volumio volumio[1142]: SPOTIFY: PUSH STATE SPOTIFY
Feb 11 06:28:50 volumio volumio[1142]: SPOTIFY: {"status":"play","service":"spop","title":"Serene Night - Ambient Piano Version","artist":"July Sunrise","album":"Serene Night (Ambient Piano Version)","albumart":"https://i.scdn.co/image/ab67616d00001e02cd6cfeb6f3b78edeb840fcdd","uri":"spotify:track:2t0LK6NCvQKdJuyI3qgkra","trackType":"spotify","seek":0,"duration":60,"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 11 06:28:50 volumio volumio[1142]: info: CoreCommandRouter::servicePushState
Feb 11 06:28:50 volumio volumio[1142]: info: CoreStateMachine::pushState
Feb 11 06:28:50 volumio volumio[1142]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 11 06:28:50 volumio volumio[1142]: info: CoreCommandRouter::volumioPushState
Feb 11 06:28:50 volumio volumio[1142]: info: [LastFM] Current track has sufficient metadata: title (Serene Night - Ambient Piano Version) and artist (July Sunrise) passed on explicitly
Feb 11 06:28:50 volumio volumio[1142]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72
Feb 11 06:28:50 volumio go-librespot[1686]: time="2026-02-11T06:28:50-07:00" level=debug msg="handling set_options player command from social-connect-ae11c7dcdc8f10497051b7fd29ba3d5b"
Feb 11 06:28:50 volumio go-librespot[1686]: time="2026-02-11T06:28:50-07:00" level=debug msg="sending successful reply for dealer request"
Feb 11 06:28:50 volumio volumio[1142]: SPOTIFY: PUSH STATE SPOTIFY
Feb 11 06:28:50 volumio volumio[1142]: SPOTIFY: {"status":"play","service":"spop","title":"Serene Night - Ambient Piano Version","artist":"July Sunrise","album":"Serene Night (Ambient Piano Version)","albumart":"https://i.scdn.co/image/ab67616d00001e02cd6cfeb6f3b78edeb840fcdd","uri":"spotify:track:2t0LK6NCvQKdJuyI3qgkra","trackType":"spotify","seek":0,"duration":60,"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 11 06:28:50 volumio volumio[1142]: info: CoreCommandRouter::servicePushState
Feb 11 06:28:50 volumio volumio[1142]: info: CoreStateMachine::pushState
Feb 11 06:28:50 volumio volumio[1142]: info: CoreCommandRouter::volumioPushState
Feb 11 06:28:50 volumio volumio[1142]: SPOTIFY: RECEIVED VOLUMIO VOLUME 72
Feb 11 06:28:59 volumio volumio[1142]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 11 06:28:59 volumio volumio[1142]: TypeError: Cannot read properties of undefined (reading '@')
Feb 11 06:28:59 volumio volumio[1142]: at Object.callback (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:342:14)
Feb 11 06:28:59 volumio volumio[1142]: at /data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:60:13
Feb 11 06:28:59 volumio volumio[1142]: at Parser. (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:322:18)
Feb 11 06:28:59 volumio volumio[1142]: at Parser.emit (node:events:514:28)
Feb 11 06:28:59 volumio volumio[1142]: at SAXParser.onerror (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:133:26)
Feb 11 06:28:59 volumio volumio[1142]: at emit (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:631:35)
Feb 11 06:28:59 volumio volumio[1142]: at error (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:660:5)
Feb 11 06:28:59 volumio volumio[1142]: at strictFail (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:684:7)
Feb 11 06:28:59 volumio volumio[1142]: at closeTag (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:878:9)
Feb 11 06:28:59 volumio volumio[1142]: at SAXParser.write (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:1460:13)
Feb 11 06:28:59 volumio volumio[1142]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 11 06:29:00 volumio sudo[26303]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 06:28'
Feb 11 06:29:00 volumio sudo[26303]: 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025"
VOLUMIO_VERSION="4.084"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"