-- Logs begin at Thu 2026-02-26 03:39:36 -07, end at Thu 2026-02-26 03:48:21 -07. -- Feb 26 03:47:07 volumio go-librespot[1625]: time="2026-02-26T03:47:07-07:00" level=debug msg="fetched chunk 6/14, size: 524288" uri="spotify:track:6GM4ZOBDcDroldUxI8GZ2B" Feb 26 03:47:13 volumio ntpd[1187]: Soliciting pool server 103.184.124.254 Feb 26 03:47:18 volumio ntpd[1187]: Soliciting pool server 160.25.232.6 Feb 26 03:47:20 volumio go-librespot[1625]: time="2026-02-26T03:47:20-07:00" level=trace msg="sent dealer ping" Feb 26 03:47:20 volumio go-librespot[1625]: time="2026-02-26T03:47:20-07:00" level=trace msg="received dealer pong" Feb 26 03:47:21 volumio go-librespot[1625]: time="2026-02-26T03:47:21-07:00" level=debug msg="fetched chunk 7/14, size: 524288" uri="spotify:track:6GM4ZOBDcDroldUxI8GZ2B" Feb 26 03:47:22 volumio ntpd[1187]: Soliciting pool server 103.186.65.246 Feb 26 03:47:22 volumio ntpd[1187]: Soliciting pool server 45.252.250.189 Feb 26 03:47:34 volumio go-librespot[1625]: time="2026-02-26T03:47:34-07:00" level=debug msg="fetched chunk 8/14, size: 524288" uri="spotify:track:6GM4ZOBDcDroldUxI8GZ2B" Feb 26 03:47:38 volumio volumio[1198]: info: CoreCommandRouter::executeOnPlugin: spop , handleBrowseUri Feb 26 03:47:38 volumio volumio[1198]: info: In handleBrowseUri, curUri=spotify Feb 26 03:47:38 volumio volumio[1198]: info: Preload queue cleared Feb 26 03:47:38 volumio volumio[1198]: info: Preload queue cleared Feb 26 03:47:38 volumio volumio[1198]: info: Preload queue cleared Feb 26 03:47:38 volumio volumio[1198]: info: Preload queue cleared Feb 26 03:47:44 volumio volumio[1198]: info: CoreCommandRouter::volumioPause Feb 26 03:47:44 volumio volumio[1198]: info: CoreStateMachine::pause Feb 26 03:47:44 volumio volumio[1198]: info: CoreStateMachine::stPlaybackTimer Feb 26 03:47:44 volumio volumio[1198]: info: CoreStateMachine::servicePause Feb 26 03:47:44 volumio volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 03:47:44 volumio volumio[1198]: info: CoreCommandRouter::servicePause Feb 26 03:47:44 volumio volumio[1198]: info: Spotify Received pause Feb 26 03:47:44 volumio volumio[1198]: SPOTIFY: SPOTIFY PAUSE Feb 26 03:47:44 volumio volumio[1198]: SPOTIFY: {"status":"play","position":0,"title":"Ai Ngoài Anh","artist":"VSTRA","album":"Triệu (Phase 1 of 3)","albumart":"https://i.scdn.co/image/ab67616d0000b2731e3ae4d328b0937f13e52c9f","uri":"spotify:track:6GM4ZOBDcDroldUxI8GZ2B","trackType":"spotify","codec":"ogg","seek":0,"duration":199,"samplerate":"320 kbps","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":75,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"spotify","volatile":false,"service":"spop"} Feb 26 03:47:44 volumio volumio[1198]: info: Sending Spotify command to local API: /player/pause Feb 26 03:47:44 volumio go-librespot[1625]: time="2026-02-26T03:47:44-07:00" level=debug msg="pause track at 78584ms" Feb 26 03:47:44 volumio go-librespot[1625]: time="2026-02-26T03:47:44-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 26 03:47:44 volumio go-librespot[1625]: time="2026-02-26T03:47:44-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 26 03:47:44 volumio go-librespot[1625]: time="2026-02-26T03:47:44-07:00" level=trace msg="emitting websocket event: paused" Feb 26 03:47:44 volumio volumio[1198]: SPOTIFY: received: {"type":"paused","data":{"context_uri":"spotify:track:6GM4ZOBDcDroldUxI8GZ2B","uri":"spotify:track:6GM4ZOBDcDroldUxI8GZ2B","play_origin":"go-librespot"}} Feb 26 03:47:44 volumio volumio[1198]: SPOTIFY: PUSH STATE SPOTIFY Feb 26 03:47:44 volumio volumio[1198]: SPOTIFY: {"status":"pause","service":"spop","title":"Ai Ngoài Anh","artist":"VSTRA, Tyronee","album":"Triệu (Phase 1 of 3)","albumart":"https://i.scdn.co/image/ab67616d00001e021e3ae4d328b0937f13e52c9f","uri":"spotify:track:6GM4ZOBDcDroldUxI8GZ2B","trackType":"spotify","seek":77000,"duration":199,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 26 03:47:44 volumio volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 03:47:44 volumio volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 03:47:44 volumio volumio[1198]: verbose: STATE SERVICE {"status":"pause","service":"spop","title":"Ai Ngoài Anh","artist":"VSTRA, Tyronee","album":"Triệu (Phase 1 of 3)","albumart":"https://i.scdn.co/image/ab67616d00001e021e3ae4d328b0937f13e52c9f","uri":"spotify:track:6GM4ZOBDcDroldUxI8GZ2B","trackType":"spotify","seek":77000,"duration":199,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 26 03:47:44 volumio volumio[1198]: verbose: CURRENT POSITION 0 Feb 26 03:47:44 volumio volumio[1198]: info: CoreStateMachine::syncState stateService pause Feb 26 03:47:44 volumio volumio[1198]: info: CoreStateMachine::syncState currentStatus pause Feb 26 03:47:44 volumio volumio[1198]: info: CoreStateMachine::pushState Feb 26 03:47:44 volumio volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 03:47:44 volumio volumio[1198]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 03:47:44 volumio volumio[1198]: info: CoreCommandRouter::volumioPushState Feb 26 03:47:44 volumio volumio[1198]: info: CoreStateMachine::stPlaybackTimer Feb 26 03:47:44 volumio volumio[1198]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Feb 26 03:47:48 volumio volumio[1198]: info: CoreCommandRouter::volumioPlay Feb 26 03:47:48 volumio volumio[1198]: info: CoreStateMachine::play index undefined Feb 26 03:47:48 volumio volumio[1198]: info: CoreStateMachine::setConsumeUpdateService undefined Feb 26 03:47:48 volumio volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 03:47:48 volumio volumio[1198]: info: CoreStateMachine::startPlaybackTimer Feb 26 03:47:48 volumio volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 03:47:48 volumio volumio[1198]: info: Spotify Resume Feb 26 03:47:48 volumio volumio[1198]: info: Sending Spotify command to local API: /player/resume Feb 26 03:47:48 volumio go-librespot[1625]: time="2026-02-26T03:47:48-07:00" level=trace msg="seek to 78584ms (diff: 63ms, samples: 3465554, bytes: 2954590)" uri="spotify:track:6GM4ZOBDcDroldUxI8GZ2B" Feb 26 03:47:48 volumio go-librespot[1625]: time="2026-02-26T03:47:48-07:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Feb 26 03:47:48 volumio go-librespot[1625]: time="2026-02-26T03:47:48-07:00" level=debug msg="resume track at 78521ms" Feb 26 03:47:48 volumio volumio[1198]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Feb 26 03:47:48 volumio volumio[1198]: info: FusionDsp - ---- read samplerate from file: 44100 Feb 26 03:47:48 volumio volumio[1198]: info: FusionDsp - If filter freq >samplerate/2 then disable it Feb 26 03:47:48 volumio volumio[1198]: info: FusionDsp - {"Reload":{"result":"Ok"}} Feb 26 03:47:49 volumio go-librespot[1625]: time="2026-02-26T03:47:49-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 26 03:47:49 volumio go-librespot[1625]: time="2026-02-26T03:47:49-07:00" level=trace msg="scheduling prefetch in 90s" Feb 26 03:47:49 volumio go-librespot[1625]: time="2026-02-26T03:47:49-07:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 26 03:47:49 volumio go-librespot[1625]: time="2026-02-26T03:47:49-07:00" level=trace msg="emitting websocket event: playing" Feb 26 03:47:49 volumio volumio[1198]: SPOTIFY: received: {"type":"playing","data":{"context_uri":"spotify:track:6GM4ZOBDcDroldUxI8GZ2B","uri":"spotify:track:6GM4ZOBDcDroldUxI8GZ2B","resume":true,"play_origin":"go-librespot"}} Feb 26 03:47:49 volumio volumio[1198]: SPOTIFY: PUSH STATE SPOTIFY Feb 26 03:47:49 volumio volumio[1198]: SPOTIFY: {"status":"play","service":"spop","title":"Ai Ngoài Anh","artist":"VSTRA, Tyronee","album":"Triệu (Phase 1 of 3)","albumart":"https://i.scdn.co/image/ab67616d00001e021e3ae4d328b0937f13e52c9f","uri":"spotify:track:6GM4ZOBDcDroldUxI8GZ2B","trackType":"spotify","seek":77000,"duration":199,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 26 03:47:49 volumio volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 03:47:49 volumio volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 03:47:49 volumio volumio[1198]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Ai Ngoài Anh","artist":"VSTRA, Tyronee","album":"Triệu (Phase 1 of 3)","albumart":"https://i.scdn.co/image/ab67616d00001e021e3ae4d328b0937f13e52c9f","uri":"spotify:track:6GM4ZOBDcDroldUxI8GZ2B","trackType":"spotify","seek":77000,"duration":199,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 26 03:47:49 volumio volumio[1198]: verbose: CURRENT POSITION 0 Feb 26 03:47:49 volumio volumio[1198]: info: CoreStateMachine::syncState stateService play Feb 26 03:47:49 volumio volumio[1198]: info: CoreStateMachine::syncState currentStatus pause Feb 26 03:47:49 volumio volumio[1198]: info: CoreStateMachine::pushState Feb 26 03:47:49 volumio volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 03:47:49 volumio volumio[1198]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 03:47:49 volumio volumio[1198]: info: CoreCommandRouter::volumioPushState Feb 26 03:47:49 volumio volumio[1198]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Feb 26 03:47:49 volumio volumio[1198]: SPOTIFY: PUSH STATE SPOTIFY Feb 26 03:47:49 volumio volumio[1198]: SPOTIFY: {"status":"play","service":"spop","title":"Ai Ngoài Anh","artist":"VSTRA, Tyronee","album":"Triệu (Phase 1 of 3)","albumart":"https://i.scdn.co/image/ab67616d00001e021e3ae4d328b0937f13e52c9f","uri":"spotify:track:6GM4ZOBDcDroldUxI8GZ2B","trackType":"spotify","seek":77000,"duration":199,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 26 03:47:49 volumio volumio[1198]: info: CoreCommandRouter::servicePushState Feb 26 03:47:49 volumio volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 03:47:49 volumio volumio[1198]: verbose: STATE SERVICE {"status":"play","service":"spop","title":"Ai Ngoài Anh","artist":"VSTRA, Tyronee","album":"Triệu (Phase 1 of 3)","albumart":"https://i.scdn.co/image/ab67616d00001e021e3ae4d328b0937f13e52c9f","uri":"spotify:track:6GM4ZOBDcDroldUxI8GZ2B","trackType":"spotify","seek":77000,"duration":199,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Feb 26 03:47:49 volumio volumio[1198]: verbose: CURRENT POSITION 0 Feb 26 03:47:49 volumio volumio[1198]: info: CoreStateMachine::syncState stateService play Feb 26 03:47:49 volumio volumio[1198]: info: CoreStateMachine::syncState currentStatus play Feb 26 03:47:49 volumio volumio[1198]: info: Received an update from plugin. extracting info from payload Feb 26 03:47:49 volumio volumio[1198]: info: CoreStateMachine::pushState Feb 26 03:47:49 volumio volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 03:47:49 volumio volumio[1198]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 26 03:47:49 volumio volumio[1198]: info: CoreCommandRouter::volumioPushState Feb 26 03:47:49 volumio volumio[1198]: info: CoreStateMachine::pushState Feb 26 03:47:49 volumio volumio[1198]: info: CorePlayQueue::getTrack 0 Feb 26 03:47:49 volumio volumio[1198]: info: CoreCommandRouter::volumioPushState Feb 26 03:47:49 volumio volumio[1198]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Feb 26 03:47:49 volumio volumio[1198]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Feb 26 03:47:49 volumio volumio[1198]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Feb 26 03:47:49 volumio volumio[1198]: info: CURURI: artists:// Feb 26 03:47:49 volumio volumio[1198]: info: Preload queue cleared Feb 26 03:47:49 volumio go-librespot[1625]: time="2026-02-26T03:47:49-07:00" level=trace msg="received accesspoint ping" Feb 26 03:47:49 volumio go-librespot[1625]: time="2026-02-26T03:47:49-07:00" level=trace msg="received accesspoint pong ack" Feb 26 03:47:50 volumio go-librespot[1625]: time="2026-02-26T03:47:50-07:00" level=trace msg="sent dealer ping" Feb 26 03:47:50 volumio go-librespot[1625]: time="2026-02-26T03:47:50-07:00" level=trace msg="received dealer pong" Feb 26 03:47:51 volumio go-librespot[1625]: time="2026-02-26T03:47:51-07:00" level=debug msg="fetched chunk 9/14, size: 524288" uri="spotify:track:6GM4ZOBDcDroldUxI8GZ2B" Feb 26 03:47:55 volumio volumio[1198]: info: CoreCommandRouter::executeOnPlugin: youtube2 , handleBrowseUri Feb 26 03:47:55 volumio volumio[1198]: info: [youtube2-browse] browseUri: youtube2 Feb 26 03:47:55 volumio volumio[1198]: info: [youtube2] InnertubeLoader: creating Innertube instance... Feb 26 03:48:00 volumio volumio[1198]: [YOUTUBEJS][Player]: Failed to extract signature decipher algorithm. Feb 26 03:48:00 volumio volumio[1198]: info: [youtube2] InnertubeLoader: obtaining po_token by visitorData... Feb 26 03:48:01 volumio volumio[1198]: info: [youtube2] InnertubeLoader: obtained po_token (expires in 43200 seconds) Feb 26 03:48:01 volumio volumio[1198]: info: [youtube2] InnertubeLoader: re-create Innertube instance with po_token Feb 26 03:48:01 volumio volumio[1198]: info: [youtube2] InnertubeLoader: creating Innertube instance with po_token... Feb 26 03:48:03 volumio volumio[1198]: [YOUTUBEJS][Player]: Failed to extract signature decipher algorithm. Feb 26 03:48:03 volumio volumio[1198]: info: [youtube2] InnertubeLoader: going to refresh po_token in 43100 seconds Feb 26 03:48:03 volumio volumio[1198]: info: Preload queue cleared Feb 26 03:48:03 volumio volumio[1198]: info: Preload queue cleared Feb 26 03:48:04 volumio go-librespot[1625]: time="2026-02-26T03:48:04-07:00" level=debug msg="fetched chunk 10/14, size: 524288" uri="spotify:track:6GM4ZOBDcDroldUxI8GZ2B" Feb 26 03:48:18 volumio go-librespot[1625]: time="2026-02-26T03:48:18-07:00" level=debug msg="fetched chunk 11/14, size: 524288" uri="spotify:track:6GM4ZOBDcDroldUxI8GZ2B" Feb 26 03:48:20 volumio volumio[1198]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Wanbi/ef8d278b-d0eb-49e9-99ff-776b2769f49f.jpg' Feb 26 03:48:20 volumio go-librespot[1625]: time="2026-02-26T03:48:20-07:00" level=trace msg="sent dealer ping" Feb 26 03:48:20 volumio go-librespot[1625]: time="2026-02-26T03:48:20-07:00" level=trace msg="received dealer pong" Feb 26 03:48:21 volumio ntpd[1187]: Soliciting pool server 103.221.223.185 Feb 26 03:48:21 volumio volumio[1198]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 03:48:21 volumio volumio[1198]: TypeError: Cannot read property 'slice' of null Feb 26 03:48:21 volumio volumio[1198]: at download (/volumio/app/plugins/miscellanea/albumart/albumart.js:718:41) Feb 26 03:48:21 volumio volumio[1198]: at ClientRequest. (/volumio/app/plugins/miscellanea/albumart/albumart.js:728:7) Feb 26 03:48:21 volumio volumio[1198]: at Object.onceWrapper (events.js:520:26) Feb 26 03:48:21 volumio volumio[1198]: at ClientRequest.emit (events.js:400:28) Feb 26 03:48:21 volumio volumio[1198]: at HTTPParser.parserOnIncomingClient [as onIncoming] (_http_client.js:647:27) Feb 26 03:48:21 volumio volumio[1198]: at HTTPParser.parserOnHeadersComplete (_http_common.js:127:17) Feb 26 03:48:21 volumio volumio[1198]: at TLSSocket.socketOnData (_http_client.js:515:22) Feb 26 03:48:21 volumio volumio[1198]: at TLSSocket.emit (events.js:400:28) Feb 26 03:48:21 volumio volumio[1198]: at addChunk (internal/streams/readable.js:293:12) Feb 26 03:48:21 volumio volumio[1198]: at readableAddChunk (internal/streams/readable.js:267:9) Feb 26 03:48:21 volumio volumio[1198]: at TLSSocket.Readable.push (internal/streams/readable.js:206:10) Feb 26 03:48:21 volumio volumio[1198]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:188:23) Feb 26 03:48:21 volumio volumio[1198]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 26 03:48:21 volumio sudo[3363]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-02-26 03:47 Feb 26 03:48:21 volumio sudo[3363]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="5d50cd80bebce60dddccd7f5e813d656e28ca4cd" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="7840f283c310c38bfe939a4c485727a6ff6a0ce1" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 21 Oct 2025 04:19:36 PM CEST" VOLUMIO_VERSION="3.866" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="a531aa6bc68498be155aace11c795690"