Dec 15 14:46:08 volumiopi volumio[1808]: verbose: New Socket.io Connection to 192.168.0.105:3000 from 192.168.0.96 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5
Dec 15 14:46:08 volumiopi volumio[1808]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Dec 15 14:46:08 volumiopi volumio[1808]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 15 14:46:08 volumiopi volumio[1808]: info: Discovery: Getting this device information
Dec 15 14:46:08 volumiopi volumio[1808]: info: CoreCommandRouter::volumioGetState
Dec 15 14:46:08 volumiopi volumio[1808]: info: CorePlayQueue::getTrack 4
Dec 15 14:46:08 volumiopi volumio[1808]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 15 14:46:09 volumiopi volumio[1808]: verbose: New Socket.io Connection to 192.168.0.105 from 192.168.0.96 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 18_7 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 6
Dec 15 14:46:09 volumiopi volumio[1808]: info: CoreCommandRouter::volumioGetState
Dec 15 14:46:09 volumiopi volumio[1808]: info: CorePlayQueue::getTrack 4
Dec 15 14:46:09 volumiopi volumio[1808]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Dec 15 14:46:09 volumiopi volumio[1808]: info: Listing playlists
Dec 15 14:46:09 volumiopi volumio[1808]: info: CoreCommandRouter::volumioGetQueue
Dec 15 14:46:09 volumiopi volumio[1808]: info: CoreStateMachine::getQueue
Dec 15 14:46:09 volumiopi volumio[1808]: info: CorePlayQueue::getQueue
Dec 15 14:46:09 volumiopi volumio[1808]: info: CoreCommandRouter::volumioGetVisibleSources
Dec 15 14:46:09 volumiopi volumio[1808]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreCommandRouter::volumioPause
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreStateMachine::pause
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreStateMachine::stPlaybackTimer
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreStateMachine::servicePause
Dec 15 14:46:12 volumiopi volumio[1808]: info: CorePlayQueue::getTrack 4
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreCommandRouter::servicePause
Dec 15 14:46:12 volumiopi volumio[1808]: info: ControllerMpd::pause
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: ControllerMpd::sendMpdCommand pause
Dec 15 14:46:12 volumiopi volumio[1808]: info:
Dec 15 14:46:12 volumiopi volumio[1808]: ---------------------------- MPD announces state update: player
Dec 15 14:46:12 volumiopi volumio[1808]: info: sendMpdCommand pause took 1 milliseconds
Dec 15 14:46:12 volumiopi volumio[1808]: info: ControllerMpd::getState
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: ControllerMpd::sendMpdCommand status
Dec 15 14:46:12 volumiopi volumio[1808]: info:
Dec 15 14:46:12 volumiopi volumio[1808]: ---------------------------- MPD announces state update: player
Dec 15 14:46:12 volumiopi volumio[1808]: info: ControllerMpd::getState
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: ControllerMpd::sendMpdCommand status
Dec 15 14:46:12 volumiopi volumio[1808]: info:
Dec 15 14:46:12 volumiopi volumio[1808]: ---------------------------- MPD announces state update: player
Dec 15 14:46:12 volumiopi volumio[1808]: info: ControllerMpd::getState
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: ControllerMpd::sendMpdCommand status
Dec 15 14:46:12 volumiopi volumio[1808]: info: sendMpdCommand status took 2 milliseconds
Dec 15 14:46:12 volumiopi volumio[1808]: info: sendMpdCommand status took 2 milliseconds
Dec 15 14:46:12 volumiopi volumio[1808]: info: sendMpdCommand status took 1 milliseconds
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: ControllerMpd::parseState
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: ControllerMpd::parseState
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: ControllerMpd::parseState
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Dec 15 14:46:12 volumiopi volumio[1808]: info: sendMpdCommand playlistinfo took 3 milliseconds
Dec 15 14:46:12 volumiopi volumio[1808]: info: sendMpdCommand playlistinfo took 3 milliseconds
Dec 15 14:46:12 volumiopi volumio[1808]: info: sendMpdCommand playlistinfo took 4 milliseconds
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: ControllerMpd::parseTrackInfo
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: ControllerMpd::parseTrackInfo
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: ControllerMpd::parseTrackInfo
Dec 15 14:46:12 volumiopi volumio[1808]: info: ControllerMpd::pushState
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreCommandRouter::servicePushState
Dec 15 14:46:12 volumiopi volumio[1808]: info: CorePlayQueue::getTrack 4
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":218270,"duration":240,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Another Brick In The Wall Part 2","artist":"Pink Floyd","album":"The Wall - Disc 1","uri":"NAS/diskstation/Pink_Floyd/The Wall - Disc 1/05 Another Brick In The Wall Part 2.mp3","trackType":"mp3"}
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: CURRENT POSITION 4
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreStateMachine::syncState stateService pause
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreStateMachine::syncState currentStatus pause
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreStateMachine::pushState
Dec 15 14:46:12 volumiopi volumio[1808]: info: CorePlayQueue::getTrack 4
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreCommandRouter::volumioPushState
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreStateMachine::stPlaybackTimer
Dec 15 14:46:12 volumiopi volumio[1808]: info: ControllerMpd::pushState
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreCommandRouter::servicePushState
Dec 15 14:46:12 volumiopi volumio[1808]: info: CorePlayQueue::getTrack 4
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":218270,"duration":240,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Another Brick In The Wall Part 2","artist":"Pink Floyd","album":"The Wall - Disc 1","uri":"NAS/diskstation/Pink_Floyd/The Wall - Disc 1/05 Another Brick In The Wall Part 2.mp3","trackType":"mp3"}
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: CURRENT POSITION 4
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreStateMachine::syncState stateService pause
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreStateMachine::syncState currentStatus pause
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreStateMachine::pushState
Dec 15 14:46:12 volumiopi volumio[1808]: info: CorePlayQueue::getTrack 4
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreCommandRouter::volumioPushState
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreStateMachine::stPlaybackTimer
Dec 15 14:46:12 volumiopi volumio[1808]: info: ControllerMpd::pushState
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreCommandRouter::servicePushState
Dec 15 14:46:12 volumiopi volumio[1808]: info: CorePlayQueue::getTrack 4
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":218270,"duration":240,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Another Brick In The Wall Part 2","artist":"Pink Floyd","album":"The Wall - Disc 1","uri":"NAS/diskstation/Pink_Floyd/The Wall - Disc 1/05 Another Brick In The Wall Part 2.mp3","trackType":"mp3"}
Dec 15 14:46:12 volumiopi volumio[1808]: verbose: CURRENT POSITION 4
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreStateMachine::syncState stateService pause
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreStateMachine::syncState currentStatus pause
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreStateMachine::pushState
Dec 15 14:46:12 volumiopi volumio[1808]: info: CorePlayQueue::getTrack 4
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreCommandRouter::volumioPushState
Dec 15 14:46:12 volumiopi volumio[1808]: info: CoreStateMachine::stPlaybackTimer
Dec 15 14:46:12 volumiopi volumio[1808]: info: ------------------------------ 30ms
Dec 15 14:46:12 volumiopi volumio[1808]: info: ------------------------------ 29ms
Dec 15 14:46:12 volumiopi volumio[1808]: info: ------------------------------ 29ms
Dec 15 14:46:14 volumiopi volumio[1808]: verbose: New Socket.io Connection to 192.168.0.105:3000 from 192.168.0.96 UA: Dart/3.9 (dart:io) Engine version: 3 Transport: websocket Total Clients: 6
Dec 15 14:46:14 volumiopi volumio[1808]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Dec 15 14:46:14 volumiopi volumio[1808]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Dec 15 14:46:14 volumiopi volumio[1808]: info: Discovery: Getting this device information
Dec 15 14:46:14 volumiopi volumio[1808]: info: CoreCommandRouter::volumioGetState
Dec 15 14:46:14 volumiopi volumio[1808]: info: CorePlayQueue::getTrack 4
Dec 15 14:46:14 volumiopi volumio[1808]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Dec 15 14:47:26 volumiopi go-librespot[2165]: time="2025-12-15T14:47:26Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Dec 15 14:47:26 volumiopi volumio[1808]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 15 14:47:26 volumiopi volumio[1808]: Error: socket hang up
Dec 15 14:47:26 volumiopi volumio[1808]: at connResetException (node:internal/errors:720:14)
Dec 15 14:47:26 volumiopi volumio[1808]: at Socket.socketOnEnd (node:_http_client:519:23)
Dec 15 14:47:26 volumiopi volumio[1808]: at Socket.emit (node:events:526:35)
Dec 15 14:47:26 volumiopi volumio[1808]: at endReadableNT (node:internal/streams/readable:1376:12)
Dec 15 14:47:26 volumiopi volumio[1808]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Dec 15 14:47:26 volumiopi volumio[1808]: code: 'ECONNRESET',
Dec 15 14:47:26 volumiopi volumio[1808]: response: undefined
Dec 15 14:47:26 volumiopi volumio[1808]: }
Dec 15 14:47:26 volumiopi volumio[1808]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 15 14:47:26 volumiopi systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Dec 15 14:47:26 volumiopi systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Dec 15 14:47:26 volumiopi systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Dec 15 14:47:26 volumiopi sudo[4037]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 14:46'
Dec 15 14:47:26 volumiopi sudo[4037]: 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="3a3cfe435f8bb2bc94a920662e91a4ef35bc8e7c"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="8bcc10c3dbcbcb349e9887dc0527d54876b32688"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue Dec 2 11:51:19 UTC 2025"
VOLUMIO_VERSION="4.072"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="e5001581b220b096097cf8f46a54d4f1"