Feb 23 08:31:12 volumiold go-librespot[16513]: time="2026-02-23T08:31:12-05:00" level=trace msg="sent dealer ping" Feb 23 08:31:12 volumiold go-librespot[16513]: time="2026-02-23T08:31:12-05:00" level=trace msg="received dealer pong" Feb 23 08:31:19 volumiold sshd[5748]: Accepted password for volumio from 192.168.1.170 port 61823 ssh2 Feb 23 08:31:19 volumiold sshd[5748]: pam_unix(sshd:session): session opened for user volumio(uid=1000) by (uid=0) Feb 23 08:31:19 volumiold systemd-logind[685]: New session 21 of user volumio. Feb 23 08:31:20 volumiold systemd[1]: Created slice user-1000.slice - User Slice of UID 1000. Feb 23 08:31:20 volumiold systemd[1]: Starting user-runtime-dir@1000.service - User Runtime Directory /run/user/1000... Feb 23 08:31:20 volumiold systemd[1]: Finished user-runtime-dir@1000.service - User Runtime Directory /run/user/1000. Feb 23 08:31:20 volumiold systemd[1]: Starting user@1000.service - User Manager for UID 1000... Feb 23 08:31:20 volumiold (systemd)[5751]: pam_unix(systemd-user:session): session opened for user volumio(uid=1000) by (uid=0) Feb 23 08:31:20 volumiold systemd[5751]: Queued start job for default target default.target. Feb 23 08:31:20 volumiold systemd[5751]: Created slice app.slice - User Application Slice. Feb 23 08:31:20 volumiold systemd[5751]: Reached target paths.target - Paths. Feb 23 08:31:20 volumiold systemd[5751]: Reached target timers.target - Timers. Feb 23 08:31:20 volumiold systemd[5751]: Listening on dirmngr.socket - GnuPG network certificate management daemon. Feb 23 08:31:20 volumiold systemd[5751]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers). Feb 23 08:31:20 volumiold systemd[5751]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted). Feb 23 08:31:20 volumiold systemd[5751]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation). Feb 23 08:31:20 volumiold systemd[5751]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache. Feb 23 08:31:20 volumiold systemd[5751]: Reached target sockets.target - Sockets. Feb 23 08:31:20 volumiold systemd[5751]: Reached target basic.target - Basic System. Feb 23 08:31:20 volumiold systemd[1]: Started user@1000.service - User Manager for UID 1000. Feb 23 08:31:20 volumiold systemd[5751]: Started mpris-proxy.service - Bluetooth mpris proxy. Feb 23 08:31:20 volumiold systemd[5751]: Reached target default.target - Main User Target. Feb 23 08:31:20 volumiold systemd[5751]: Startup finished in 656ms. Feb 23 08:31:20 volumiold systemd[1]: Started session-21.scope - Session 21 of User volumio. Feb 23 08:31:20 volumiold mpris-proxy[5766]: Can't get on session bus Feb 23 08:31:20 volumiold systemd[5751]: mpris-proxy.service: Main process exited, code=exited, status=1/FAILURE Feb 23 08:31:20 volumiold systemd[5751]: mpris-proxy.service: Failed with result 'exit-code'. Feb 23 08:31:20 volumiold sshd[5748]: pam_env(sshd:session): deprecated reading of user environment enabled Feb 23 08:31:23 volumiold sudo[5781]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/journalctl -f Feb 23 08:31:23 volumiold sudo[5781]: pam_unix(sudo:session): session opened for user root(uid=0) by volumio(uid=1000) Feb 23 08:31:26 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 08:31:26 volumiold volumio[16318]: info: Received Get System Info Feb 23 08:31:26 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 08:31:26 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 08:31:26 volumiold volumio[16318]: info: Discovery: Getting this device information Feb 23 08:31:26 volumiold volumio[16318]: info: CoreCommandRouter::volumioGetState Feb 23 08:31:26 volumiold volumio[16318]: debug: CoreStateMachine::getState Feb 23 08:31:26 volumiold volumio[16318]: info: CorePlayQueue::getTrack 0 Feb 23 08:31:26 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 08:31:26 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 23 08:31:26 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Feb 23 08:31:31 volumiold volumio[16318]: info: CoreCommandRouter::volumioGetState Feb 23 08:31:31 volumiold volumio[16318]: debug: CoreStateMachine::getState Feb 23 08:31:31 volumiold volumio[16318]: info: CorePlayQueue::getTrack 0 Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 23 08:31:32 volumiold volumio[16318]: info: Retrieving Cloud Streaming UI Feb 23 08:31:32 volumiold volumio[16318]: info: Getting Tidal Cloud Configuration Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 23 08:31:32 volumiold volumio[16318]: info: Getting Qobuz Cloud Configuration Feb 23 08:31:32 volumiold volumio[16318]: info: Asking plugin for UI Config Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 23 08:31:32 volumiold volumio[16318]: info: Getting Spotify Cloud Configuration Feb 23 08:31:32 volumiold volumio[16318]: info: Asking plugin for UI Config Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 23 08:31:32 volumiold volumio[16318]: info: Saving Spotify Acccount Feb 23 08:31:32 volumiold volumio[16318]: info: Got Tidal Cloud Configuration Feb 23 08:31:32 volumiold volumio[16318]: info: Got it Feb 23 08:31:32 volumiold volumio[16318]: info: Got it Feb 23 08:31:32 volumiold volumio[16318]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 23 08:31:32 volumiold volumio[16318]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave') Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::volumioGetBrowseSources Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::volumioGetBrowseSources Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::volumioGetBrowseSources Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Feb 23 08:31:32 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Feb 23 08:31:34 volumiold volumio[16318]: info: CoreCommandRouter::volumioGetState Feb 23 08:31:34 volumiold volumio[16318]: debug: CoreStateMachine::getState Feb 23 08:31:34 volumiold volumio[16318]: info: CorePlayQueue::getTrack 0 Feb 23 08:31:35 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Feb 23 08:31:35 volumiold volumio[16318]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Feb 23 08:31:35 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Feb 23 08:31:35 volumiold volumio[16318]: debug: API:emitFavourites Feb 23 08:31:35 volumiold volumio[16318]: info: Received Get System Version Feb 23 08:31:35 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 08:31:35 volumiold volumio[16318]: info: Received Get System Info Feb 23 08:31:35 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Feb 23 08:31:35 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Feb 23 08:31:35 volumiold volumio[16318]: info: Discovery: Getting this device information Feb 23 08:31:35 volumiold volumio[16318]: info: CoreCommandRouter::volumioGetState Feb 23 08:31:35 volumiold volumio[16318]: debug: CoreStateMachine::getState Feb 23 08:31:35 volumiold volumio[16318]: info: CorePlayQueue::getTrack 0 Feb 23 08:31:35 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Feb 23 08:31:36 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Feb 23 08:31:36 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Feb 23 08:31:42 volumiold go-librespot[16513]: time="2026-02-23T08:31:42-05:00" level=trace msg="sent dealer ping" Feb 23 08:31:42 volumiold go-librespot[16513]: time="2026-02-23T08:31:42-05:00" level=trace msg="received dealer pong" Feb 23 08:31:49 volumiold go-librespot[16513]: time="2026-02-23T08:31:49-05:00" level=trace msg="received accesspoint ping" Feb 23 08:31:49 volumiold go-librespot[16513]: time="2026-02-23T08:31:49-05:00" level=trace msg="received accesspoint pong ack" Feb 23 08:31:58 volumiold volumio[16318]: info: CoreCommandRouter::getUIConfigOnPlugin Feb 23 08:32:11 volumiold volumio[16318]: info: CALLMETHOD: user_interface upc_search setOptions [object Object] Feb 23 08:32:11 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: upc_search , setOptions Feb 23 08:32:11 volumiold volumio[16318]: info: UPC_SEARCH::setOptions :{"onSearch":{"value":3,"label":"Look up UPC data only"}} Feb 23 08:32:12 volumiold volumio[16318]: info: CALLMETHOD: user_interface upc_search setOptions [object Object] Feb 23 08:32:12 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: upc_search , setOptions Feb 23 08:32:12 volumiold volumio[16318]: info: UPC_SEARCH::setOptions :{"onSearch":{"value":3,"label":"Look up UPC data only"}} Feb 23 08:32:12 volumiold go-librespot[16513]: time="2026-02-23T08:32:12-05:00" level=trace msg="sent dealer ping" Feb 23 08:32:12 volumiold go-librespot[16513]: time="2026-02-23T08:32:12-05:00" level=trace msg="received dealer pong" Feb 23 08:32:16 volumiold volumio[16318]: info: CALLMETHOD: user_interface upc_search searchAlbumArtist [object Object] Feb 23 08:32:16 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: upc_search , searchAlbumArtist Feb 23 08:32:16 volumiold volumio[16318]: debug: UPC_SEARCH::searchAlbumArtist got state: Feb 23 08:32:16 volumiold volumio[16318]: debug: {"artist":"Evelyne","album":"Test pattern"} Feb 23 08:32:16 volumiold volumio[16318]: debug: UPC_SEARCH::searchAlbumArtist emitting 'search' with data: Feb 23 08:32:16 volumiold volumio[16318]: {"value":"evelyne test pattern"} Feb 23 08:32:16 volumiold volumio[16318]: Searching all installed plugins Feb 23 08:32:16 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 08:32:16 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: , search Feb 23 08:32:16 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: mpd , search Feb 23 08:32:16 volumiold volumio[16318]: info: CoreCommandRouter::executeOnPlugin: spop , search Feb 23 08:32:16 volumiold volumio[16318]: info: New access token = BQBRvNW8TWxgg4DsTl237FpxI9bOhaD_NY6-MeVZX16F_4PiRLQ6t4dq0JBnnVmxwLLm135VBppna0U6yaSgAOnNtzta_uXaSUdcARZKL8qKSe3LbDiGLTZgBt7nTlpqHkOOjxvxjkLJQR2bb6EtLFfWrP1vH6AK3mdnegt377PCoJPu3qTw2TTbDk_s4KpI-65b_Ffv-pvSD1XnUOGuY95lYMnu9G_nlCnplJneBezXndcZqhIhXQ3Dos4LM3lJhl61qVy2g72M2We43xxS5G-n10ST6RhfRmWvd3mFp2fWkZS4p6YC9jlq Feb 23 08:32:19 volumiold volumio[16318]: info: All search sources collected, pushing search results Feb 23 08:32:19 volumiold volumio[16318]: debug: Response! Feb 23 08:32:19 volumiold volumio[16318]: debug: UPC_SEARCH::onSearchResults got data Feb 23 08:32:19 volumiold volumio[16318]: debug: UPC_SEARCH::onSearchResults extracted raw albums: Feb 23 08:32:19 volumiold volumio[16318]: debug: UPC_SEARCH::onSearchResults local albums: Feb 23 08:32:19 volumiold volumio[16318]: debug: None! Feb 23 08:32:19 volumiold volumio[16318]: debug: UPC_SEARCH::subdivideString attempting to shorten evelyne Feb 23 08:32:19 volumiold volumio[16318]: debug: UPC_SEARCH::subdivideString results evelyne Feb 23 08:32:19 volumiold volumio[16318]: debug: UPC_SEARCH::subdivideString attempting to shorten test pattern Feb 23 08:32:19 volumiold volumio[16318]: debug: UPC_SEARCH::subdivideString results test pattern Feb 23 08:32:19 volumiold volumio[16318]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 08:32:19 volumiold volumio[16318]: TypeError: Cannot read properties of undefined (reading 'length') Feb 23 08:32:19 volumiold volumio[16318]: at upcSearch.onSearchResults (/data/plugins/user_interface/upc_search/index.js:516:29) Feb 23 08:32:19 volumiold volumio[16318]: at Socket. (/data/plugins/user_interface/upc_search/index.js:373:8) Feb 23 08:32:19 volumiold volumio[16318]: at Socket.on (/data/plugins/user_interface/upc_search/node_modules/component-emitter/index.js:65:8) Feb 23 08:32:19 volumiold volumio[16318]: at Emitter.emit (/data/plugins/user_interface/upc_search/node_modules/component-emitter/index.js:145:20) Feb 23 08:32:19 volumiold volumio[16318]: at Socket.onevent (/data/plugins/user_interface/upc_search/node_modules/socket.io-client/lib/socket.js:278:10) Feb 23 08:32:19 volumiold volumio[16318]: at Socket.onpacket (/data/plugins/user_interface/upc_search/node_modules/socket.io-client/lib/socket.js:236:12) Feb 23 08:32:19 volumiold volumio[16318]: at Manager. (/data/plugins/user_interface/upc_search/node_modules/component-bind/index.js:21:15) Feb 23 08:32:19 volumiold volumio[16318]: at Emitter.emit (/data/plugins/user_interface/upc_search/node_modules/component-emitter/index.js:145:20) Feb 23 08:32:19 volumiold volumio[16318]: at Manager.ondecoded (/data/plugins/user_interface/upc_search/node_modules/socket.io-client/lib/manager.js:349:8) Feb 23 08:32:19 volumiold volumio[16318]: at Decoder. (/data/plugins/user_interface/upc_search/node_modules/component-bind/index.js:21:15) Feb 23 08:32:19 volumiold volumio[16318]: at Emitter.emit (/data/plugins/user_interface/upc_search/node_modules/component-emitter/index.js:145:20) Feb 23 08:32:19 volumiold volumio[16318]: at Decoder.add (/data/plugins/user_interface/upc_search/node_modules/socket.io-parser/index.js:254:12) Feb 23 08:32:19 volumiold volumio[16318]: at Manager.ondata (/data/plugins/user_interface/upc_search/node_modules/socket.io-client/lib/manager.js:339:16) Feb 23 08:32:19 volumiold volumio[16318]: at Socket. (/data/plugins/user_interface/upc_search/node_modules/component-bind/index.js:21:15) Feb 23 08:32:19 volumiold volumio[16318]: at Emitter.emit (/data/plugins/user_interface/upc_search/node_modules/component-emitter/index.js:145:20) Feb 23 08:32:19 volumiold volumio[16318]: at Socket.onPacket (/data/plugins/user_interface/upc_search/node_modules/engine.io-client/lib/socket.js:461:14) Feb 23 08:32:19 volumiold volumio[16318]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 08:32:20 volumiold sudo[5902]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-23 08:31' Feb 23 08:32:20 volumiold sudo[5902]: 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"