-- Logs begin at Thu 2019-02-14 19:11:59 JST, end at Sun 2026-01-11 06:24:25 JST. -- Jan 11 06:23:05 volumio go-librespot[1340]: time="2026-01-11T06:23:05+09:00" level=debug msg="fetched chunk 15/18, size: 524288" uri="spotify:track:16i6N8Sl3CRuzD4FBjDi7Y" Jan 11 06:23:16 volumio go-librespot[1340]: time="2026-01-11T06:23:16+09:00" level=debug msg="fetched chunk 16/18, size: 524288" uri="spotify:track:16i6N8Sl3CRuzD4FBjDi7Y" Jan 11 06:23:27 volumio go-librespot[1340]: time="2026-01-11T06:23:27+09:00" level=trace msg="sent dealer ping" Jan 11 06:23:27 volumio go-librespot[1340]: time="2026-01-11T06:23:27+09:00" level=trace msg="received dealer pong" Jan 11 06:23:27 volumio go-librespot[1340]: time="2026-01-11T06:23:27+09:00" level=debug msg="fetched chunk 17/18, size: 524288" uri="spotify:track:16i6N8Sl3CRuzD4FBjDi7Y" Jan 11 06:23:39 volumio go-librespot[1340]: time="2026-01-11T06:23:39+09:00" level=debug msg="fetched chunk 18/18, size: 133888" uri="spotify:track:16i6N8Sl3CRuzD4FBjDi7Y" Jan 11 06:23:46 volumio go-librespot[1340]: time="2026-01-11T06:23:46+09:00" level=debug msg="prefetching next track" uri="spotify:track:6TibCer4DqKo2ja2zXINEc" Jan 11 06:23:46 volumio go-librespot[1340]: time="2026-01-11T06:23:46+09:00" level=debug msg="selected format OGG_VORBIS_320 (2cc75e372cf48e9f9521362ea82c6e18091fefaa)" uri="spotify:track:6TibCer4DqKo2ja2zXINEc" Jan 11 06:23:46 volumio go-librespot[1340]: time="2026-01-11T06:23:46+09:00" level=debug msg="requested aes key for file 2cc75e372cf48e9f9521362ea82c6e18091fefaa, gid: 6TibCer4DqKo2ja2zXINEc" Jan 11 06:23:46 volumio go-librespot[1340]: time="2026-01-11T06:23:46+09:00" level=trace msg="found 2 cdn urls" uri="spotify:track:6TibCer4DqKo2ja2zXINEc" Jan 11 06:23:46 volumio go-librespot[1340]: time="2026-01-11T06:23:46+09:00" level=debug msg="fetched first chunk of 16, total size is 8165024 bytes" uri="spotify:track:6TibCer4DqKo2ja2zXINEc" Jan 11 06:23:46 volumio go-librespot[1340]: time="2026-01-11T06:23:46+09:00" level=info msg="prefetched track \"Night's Dream feat.EL.J\" (duration: 201211ms)" uri="spotify:track:6TibCer4DqKo2ja2zXINEc" Jan 11 06:23:46 volumio go-librespot[1340]: time="2026-01-11T06:23:46+09:00" level=debug msg="fetched chunk 1/15, size: 524288" uri="spotify:track:6TibCer4DqKo2ja2zXINEc" Jan 11 06:23:46 volumio go-librespot[1340]: time="2026-01-11T06:23:46+09:00" level=debug msg="fetched chunk 2/15, size: 524288" uri="spotify:track:6TibCer4DqKo2ja2zXINEc" Jan 11 06:23:46 volumio go-librespot[1340]: time="2026-01-11T06:23:46+09:00" level=debug msg="fetched chunk 3/15, size: 524288" uri="spotify:track:6TibCer4DqKo2ja2zXINEc" Jan 11 06:23:57 volumio go-librespot[1340]: time="2026-01-11T06:23:57+09:00" level=trace msg="sent dealer ping" Jan 11 06:23:57 volumio go-librespot[1340]: time="2026-01-11T06:23:57+09:00" level=trace msg="received dealer pong" Jan 11 06:24:15 volumio go-librespot[1340]: time="2026-01-11T06:24:15+09:00" level=trace msg="emitting websocket event: not_playing" Jan 11 06:24:15 volumio go-librespot[1340]: time="2026-01-11T06:24:15+09:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:6TibCer4DqKo2ja2zXINEc" Jan 11 06:24:15 volumio volumio[864]: SPOTIFY: received: {"type":"not_playing","data":{"context_uri":"spotify:album:1ZhdFEkI4kSRBog04xWUjl","uri":"spotify:track:16i6N8Sl3CRuzD4FBjDi7Y","play_origin":""}} Jan 11 06:24:15 volumio volumio[864]: error: Failed to decode event: not_playing Jan 11 06:24:15 volumio go-librespot[1340]: time="2026-01-11T06:24:15+09:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 11 06:24:15 volumio go-librespot[1340]: time="2026-01-11T06:24:15+09:00" level=trace msg="emitting websocket event: will_play" Jan 11 06:24:15 volumio volumio[864]: SPOTIFY: received: {"type":"will_play","data":{"context_uri":"spotify:album:1ZhdFEkI4kSRBog04xWUjl","uri":"spotify:track:6TibCer4DqKo2ja2zXINEc","play_origin":""}} Jan 11 06:24:15 volumio go-librespot[1340]: time="2026-01-11T06:24:15+09:00" level=info msg="loaded track \"Night's Dream feat.EL.J\" (paused: false, position: 0ms, duration: 201211ms, prefetched: true)" uri="spotify:track:6TibCer4DqKo2ja2zXINEc" Jan 11 06:24:15 volumio go-librespot[1340]: time="2026-01-11T06:24:15+09:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 11 06:24:15 volumio go-librespot[1340]: time="2026-01-11T06:24:15+09:00" level=trace msg="scheduling prefetch in 171s" Jan 11 06:24:15 volumio go-librespot[1340]: time="2026-01-11T06:24:15+09:00" level=trace msg="emitting websocket event: metadata" Jan 11 06:24:15 volumio volumio[864]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6TibCer4DqKo2ja2zXINEc","name":"Night's Dream feat.EL.J","artist_names":["発熱巫女〜ず","EL.J"],"album_name":"PLAY!","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02805d03b255e7968e609960e4","position":0,"duration":201211,"release_date":"year:2023 month:3 day:19","track_number":11,"disc_number":1}} Jan 11 06:24:15 volumio go-librespot[1340]: time="2026-01-11T06:24:15+09:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Jan 11 06:24:15 volumio go-librespot[1340]: time="2026-01-11T06:24:15+09:00" level=trace msg="emitting websocket event: playing" Jan 11 06:24:15 volumio volumio[864]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:album:1ZhdFEkI4kSRBog04xWUjl","uri":"spotify:track:6TibCer4DqKo2ja2zXINEc","resume":false,"play_origin":""}} Jan 11 06:24:15 volumio volumio[864]: SPOTIFY: PUSH STATE SPOTIFY Jan 11 06:24:15 volumio volumio[864]: SPOTIFY: {"status":"play","service":"spop","title":"Night's Dream feat.EL.J","artist":"発熱巫女〜ず, EL.J","album":"PLAY!","albumart":"https://i.scdn.co/image/ab67616d00001e02805d03b255e7968e609960e4","uri":"spotify:track:6TibCer4DqKo2ja2zXINEc","trackType":"spotify","seek":1000,"duration":201,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 11 06:24:15 volumio volumio[864]: info: CoreCommandRouter::servicePushState Jan 11 06:24:15 volumio volumio[864]: info: CoreStateMachine::pushState Jan 11 06:24:15 volumio volumio[864]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 11 06:24:15 volumio volumio[864]: info: CoreCommandRouter::volumioPushState Jan 11 06:24:15 volumio volumio[864]: info: [LastFM] Current track has sufficient metadata: title (Night's Dream feat.EL.J) and artist (発熱巫女〜ず, EL.J) passed on explicitly Jan 11 06:24:15 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 11 06:24:15 volumio volumio[864]: SPOTIFY: SPOTIFY VOLUME 57 Jan 11 06:24:15 volumio volumio[864]: SPOTIFY: VOLUMIO VOLUME 56 Jan 11 06:24:15 volumio volumio[864]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 11 06:24:16 volumio volumio[864]: SPOTIFY: PUSH STATE SPOTIFY Jan 11 06:24:16 volumio volumio[864]: SPOTIFY: {"status":"play","service":"spop","title":"Night's Dream feat.EL.J","artist":"発熱巫女〜ず, EL.J","album":"PLAY!","albumart":"https://i.scdn.co/image/ab67616d00001e02805d03b255e7968e609960e4","uri":"spotify:track:6TibCer4DqKo2ja2zXINEc","trackType":"spotify","seek":1000,"duration":201,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Jan 11 06:24:16 volumio volumio[864]: info: CoreCommandRouter::servicePushState Jan 11 06:24:16 volumio volumio[864]: info: CoreStateMachine::pushState Jan 11 06:24:16 volumio volumio[864]: info: CoreCommandRouter::volumioPushState Jan 11 06:24:16 volumio volumio[864]: SPOTIFY: RECEIVED VOLUMIO VOLUME 56 Jan 11 06:24:16 volumio volumio[864]: SPOTIFY: SPOTIFY VOLUME 57 Jan 11 06:24:16 volumio volumio[864]: SPOTIFY: VOLUMIO VOLUME 56 Jan 11 06:24:16 volumio volumio[864]: SPOTIFY: DELTA VOLUME ENOUGH: false Jan 11 06:24:24 volumio volumio[864]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 06:24:24 volumio volumio[864]: TypeError: Cannot read property '@' of undefined Jan 11 06:24:24 volumio volumio[864]: at Object.callback (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:342:14) Jan 11 06:24:24 volumio volumio[864]: at /data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:60:13 Jan 11 06:24:24 volumio volumio[864]: at Parser. (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:308:18) Jan 11 06:24:24 volumio volumio[864]: at Parser.emit (events.js:315:20) Jan 11 06:24:24 volumio volumio[864]: at SAXParser.onerror (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:123:26) Jan 11 06:24:24 volumio volumio[864]: at emit (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:624:35) Jan 11 06:24:24 volumio volumio[864]: at error (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:653:5) Jan 11 06:24:24 volumio volumio[864]: at strictFail (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:677:7) Jan 11 06:24:24 volumio volumio[864]: at closeTag (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:871:9) Jan 11 06:24:24 volumio volumio[864]: at SAXParser.write (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:1436:13) Jan 11 06:24:24 volumio volumio[864]: at Parser.exports.Parser.Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:323:31) Jan 11 06:24:24 volumio volumio[864]: at Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:5:59) Jan 11 06:24:24 volumio volumio[864]: at IncomingMessage. (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:58:14) Jan 11 06:24:24 volumio volumio[864]: at IncomingMessage.emit (events.js:327:22) Jan 11 06:24:24 volumio volumio[864]: at endReadableNT (internal/streams/readable.js:1327:12) Jan 11 06:24:24 volumio volumio[864]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Jan 11 06:24:24 volumio volumio[864]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 11 06:24:25 volumio sudo[21995]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-01-11 06:23 Jan 11 06:24:25 volumio sudo[21995]: 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="b43c85cc0006d3f1efecba101311ec96e334d1fd" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 11 Dec 2025 05:43:24 PM CET" VOLUMIO_VERSION="3.886" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="15d0241b0cd805792809f3ddf4a0fc4e"