Apr 13 22:47:07 volumiopi3 volumio[1110]: SPOTIFY: User informations: {"country":"US","display_name":"Bob","email":"robertj.furlong@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/w5cb6xs61bzu6i34rot6ovb2u"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/w5cb6xs61bzu6i34rot6ovb2u","id":"w5cb6xs61bzu6i34rot6ovb2u","images":[],"product":"premium","type":"user","uri":"spotify:user:w5cb6xs61bzu6i34rot6ovb2u"}
Apr 13 22:47:07 volumiopi3 volumio[1110]: info: Spotify Successfully logged in
Apr 13 22:47:08 volumiopi3 volumio[1110]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 13 22:47:08 volumiopi3 volumio[1110]: info: [1776145628056] CoreMusicLibrary::Adding element Spotify
Apr 13 22:47:08 volumiopi3 volumio[1110]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 13 22:47:08 volumiopi3 volumio[1110]: Cannot find translation for source Pandora Radio
Apr 13 22:47:08 volumiopi3 volumio[1110]: Cannot find translation for source Radio Paradise
Apr 13 22:47:08 volumiopi3 volumio[1110]: Cannot find translation for source FM/DAB Radio
Apr 13 22:47:08 volumiopi3 volumio[1110]: Cannot find translation for source Spotify
Apr 13 22:47:08 volumiopi3 go-librespot[1968]: time="2026-04-13T22:47:08-07:00" level=debug msg="new websocket client"
Apr 13 22:47:09 volumiopi3 volumio[1110]: info: CoreCommandRouter::volumioGetState
Apr 13 22:47:09 volumiopi3 volumio[1110]: info: CorePlayQueue::getTrack 0
Apr 13 22:47:09 volumiopi3 volumio[1110]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 13 22:47:09 volumiopi3 volumio[1110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 13 22:47:09 volumiopi3 volumio[1110]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Apr 13 22:47:09 volumiopi3 volumio[1110]: error: Plugin music_service pandora failed to complete 'onStart' in a timely fashion
Apr 13 22:47:09 volumiopi3 volumio[1110]: info: -------------------------------------------
Apr 13 22:47:09 volumiopi3 volumio[1110]: info: ----- MyVolumio plugins startup ----
Apr 13 22:47:09 volumiopi3 volumio[1110]: info: -------------------------------------------
Apr 13 22:47:09 volumiopi3 volumio[1110]: info: [MyVolumio PluginManager] Fetching plans data....
Apr 13 22:47:19 volumiopi3 go-librespot[1968]: time="2026-04-13T22:47:19-07:00" level=trace msg="sent dealer ping"
Apr 13 22:47:19 volumiopi3 go-librespot[1968]: time="2026-04-13T22:47:19-07:00" level=trace msg="received dealer pong"
Apr 13 22:47:20 volumiopi3 systemd[1]: systemd-hostnamed.service: Deactivated successfully.
Apr 13 22:47:27 volumiopi3 volumio[1110]: info: Connection to go-librespot Websocket established
Apr 13 22:47:27 volumiopi3 volumio[1110]: info: [1776145647232] ControllerPandora::PandoraHandler::reportAPIError
Apr 13 22:47:27 volumiopi3 volumio[1110]: error: [1776145647266] [Pandora] PandoraHandler::pandoraLoginAndGetStations::pandoraLogin: Pandora API Error: Unknown Error: connect ECONNRESET 208.85.41.46:443
Apr 13 22:47:30 volumiopi3 volumio[1110]: error: MyVolumio Plugin failed to start in a timely fashion
Apr 13 22:47:30 volumiopi3 volumio[1110]: [Metrics] CommandRouter: 139s 661.38ms
Apr 13 22:47:30 volumiopi3 volumio[1110]: info: CoreCommandRouter::volumiosetStartupVolume
Apr 13 22:47:30 volumiopi3 volumio[1110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 22:47:30 volumiopi3 volumio[1110]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 13 22:47:31 volumiopi3 volumio[1110]: info: CoreCommandRouter::Close All Modals sent
Apr 13 22:47:31 volumiopi3 volumio[1110]: info: CoreCommandRouter::Close All Modals sent
Apr 13 22:47:31 volumiopi3 volumio[1110]: info: Getting Spotify volume
Apr 13 22:47:49 volumiopi3 go-librespot[1968]: time="2026-04-13T22:47:49-07:00" level=trace msg="sent dealer ping"
Apr 13 22:47:49 volumiopi3 go-librespot[1968]: time="2026-04-13T22:47:49-07:00" level=trace msg="received dealer pong"
Apr 13 22:47:51 volumiopi3 volumio[1110]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Apr 13 22:47:51 volumiopi3 volumio[1110]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Apr 13 22:47:51 volumiopi3 volumio[1110]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Apr 13 22:47:51 volumiopi3 volumio[1110]: info: BOOT COMPLETED
Apr 13 22:48:05 volumiopi3 volumio[1110]: error: An error occurred while listing Spotify featured playlists Error: Client network socket disconnected before secure TLS connection was established
Apr 13 22:48:06 volumiopi3 volumio[1110]: info: An error occurred while getting Spotify ROOT Discover Folders:
Apr 13 22:48:06 volumiopi3 volumio[1110]: error: An error occurred while listing Spotify new albums Error: Client network socket disconnected before secure TLS connection was established
Apr 13 22:48:06 volumiopi3 volumio[1110]: error: An error occurred while listing Spotify categories Error: Client network socket disconnected before secure TLS connection was established
Apr 13 22:48:06 volumiopi3 volumio[1110]: info: Spotify volume: 41
Apr 13 22:48:06 volumiopi3 volumio[1110]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 13 22:48:07 volumiopi3 volumio[1110]: Error [ERR_INTERNAL_ASSERTION]: This is caused by either a bug in Node.js or incorrect usage of Node.js internals.
Apr 13 22:48:07 volumiopi3 volumio[1110]: Please open an issue with this stack trace at https://github.com/nodejs/node/issues
Apr 13 22:48:07 volumiopi3 volumio[1110]: at new NodeError (node:internal/errors:405:5)
Apr 13 22:48:07 volumiopi3 volumio[1110]: at assert (node:internal/assert:14:11)
Apr 13 22:48:07 volumiopi3 volumio[1110]: at internalConnectMultiple (node:net:1118:3)
Apr 13 22:48:07 volumiopi3 volumio[1110]: at Timeout.internalConnectMultipleTimeout (node:net:1687:3)
Apr 13 22:48:07 volumiopi3 volumio[1110]: at listOnTimeout (node:internal/timers:575:11)
Apr 13 22:48:07 volumiopi3 volumio[1110]: at process.processTimers (node:internal/timers:514:7) {
Apr 13 22:48:07 volumiopi3 volumio[1110]: code: 'ERR_INTERNAL_ASSERTION'
Apr 13 22:48:07 volumiopi3 volumio[1110]: }
Apr 13 22:48:07 volumiopi3 volumio[1110]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 13 22:48:18 volumiopi3 sudo[2193]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-04-13 22:47'
Apr 13 22:48:18 volumiopi3 sudo[2193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Apr 13 22:48:19 volumiopi3 go-librespot[1968]: time="2026-04-13T22:48:19-07:00" level=trace msg="sent dealer ping"
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="18952480e8d8c63f22208e9007a0f47a9563eae6"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Tue Mar 24 17:20:52 UTC 2026"
VOLUMIO_VERSION="4.119"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="d0c2fd9dbc5e70e58c32413c12353563"