Dec 15 22:19:00 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Dec 15 22:19:00 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Dec 15 22:19:04 volumio volumio[3298]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 15 22:19:05 volumio volumio[3298]: info: BOOT COMPLETED
Dec 15 22:19:10 volumio volumio[3298]: info: CALLMETHOD: music_service ytcr configSaveDisclaimer [object Object]
Dec 15 22:19:10 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: ytcr , configSaveDisclaimer
Dec 15 22:19:14 volumio volumio[3298]: info: CoreCommandRouter::volumioGetState
Dec 15 22:19:14 volumio volumio[3298]: info: CorePlayQueue::getTrack 0
Dec 15 22:19:15 volumio volumio[3298]: info: [yt-cast-receiver] DIAL server listening on port 8098
Dec 15 22:19:15 volumio volumio[3298]: info: CoreCommandRouter::volumioRetrievevolume
Dec 15 22:19:15 volumio volumio[3298]: Unable to parse:
Dec 15 22:19:15 volumio volumio[3298]: Simple mixer control 'PCM',0
Dec 15 22:19:15 volumio volumio[3298]: Capabilities: pswitch pswitch-joined
Dec 15 22:19:15 volumio volumio[3298]: Playback channels: Mono
Dec 15 22:19:15 volumio volumio[3298]: Mono: Playback [on]
Dec 15 22:19:15 volumio volumio[3298]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: failed to parse output
Dec 15 22:19:15 volumio volumio[3298]: Unable to parse:
Dec 15 22:19:15 volumio volumio[3298]: Simple mixer control 'PCM',0
Dec 15 22:19:15 volumio volumio[3298]: Capabilities: pswitch pswitch-joined
Dec 15 22:19:15 volumio volumio[3298]: Playback channels: Mono
Dec 15 22:19:15 volumio volumio[3298]: Mono: Playback [on]
Dec 15 22:19:15 volumio volumio[3298]: info: VolumeController:: Volume=undefined Mute =false
Dec 15 22:19:15 volumio volumio[3298]: info: CoreCommandRouter::volumioGetState
Dec 15 22:19:15 volumio volumio[3298]: info: CorePlayQueue::getTrack 0
Dec 15 22:19:15 volumio volumio[3298]: info: CoreStateMachine::pushState
Dec 15 22:19:15 volumio volumio[3298]: info: CorePlayQueue::getTrack 0
Dec 15 22:19:15 volumio volumio[3298]: info: CoreCommandRouter::volumioPushState
Dec 15 22:19:15 volumio volumio[3298]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 15 22:19:18 volumio volumio[3298]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 15 22:19:18 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions
Dec 15 22:19:18 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Dec 15 22:19:18 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Dec 15 22:19:18 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 15 22:19:18 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 15 22:19:18 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 15 22:19:18 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 15 22:19:18 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 15 22:19:18 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 15 22:19:18 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 15 22:19:18 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode
Dec 15 22:19:18 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
Dec 15 22:19:19 volumio go-librespot[3689]: time="2025-12-15T22:19:19+05:30" level=trace msg="sent dealer ping"
Dec 15 22:19:20 volumio go-librespot[3689]: time="2025-12-15T22:19:20+05:30" level=trace msg="received dealer pong"
Dec 15 22:19:34 volumio volumio[3298]: info: CoreCommandRouter::volumioGetState
Dec 15 22:19:34 volumio volumio[3298]: info: CorePlayQueue::getTrack 0
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 15 22:19:41 volumio volumio[3298]: info: Retrieving Cloud Streaming UI
Dec 15 22:19:41 volumio volumio[3298]: info: Getting Tidal Cloud Configuration
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 15 22:19:41 volumio volumio[3298]: info: Getting Qobuz Cloud Configuration
Dec 15 22:19:41 volumio volumio[3298]: info: Asking plugin for UI Config
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 15 22:19:41 volumio volumio[3298]: info: Getting Spotify Cloud Configuration
Dec 15 22:19:41 volumio volumio[3298]: info: Asking plugin for UI Config
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 15 22:19:41 volumio volumio[3298]: info: Saving Spotify Acccount
Dec 15 22:19:41 volumio volumio[3298]: info: Got Tidal Cloud Configuration
Dec 15 22:19:41 volumio volumio[3298]: info: Got it
Dec 15 22:19:41 volumio volumio[3298]: info: Got it
Dec 15 22:19:41 volumio volumio[3298]: error: Could not retrieve Spotify Config from plugin Spotify: no section found
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 15 22:19:41 volumio volumio[3298]: error: Error retrieving Highresaudio conf: TypeError: Cannot read properties of undefined (reading 'onSave')
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::volumioGetBrowseSources
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::volumioGetBrowseSources
Dec 15 22:19:41 volumio volumio[3298]: info: CoreCommandRouter::volumioGetBrowseSources
Dec 15 22:19:42 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Dec 15 22:19:42 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares
Dec 15 22:19:46 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Dec 15 22:19:49 volumio go-librespot[3689]: time="2025-12-15T22:19:49+05:30" level=trace msg="sent dealer ping"
Dec 15 22:19:49 volumio go-librespot[3689]: time="2025-12-15T22:19:49+05:30" level=trace msg="received dealer pong"
Dec 15 22:19:50 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Dec 15 22:19:54 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Dec 15 22:19:54 volumio volumio[3298]: info: Disabling MyMusic plugin upnp_browser
Dec 15 22:19:54 volumio volumio[3298]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesMedia Servers
Dec 15 22:19:54 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 15 22:19:54 volumio volumio[3298]: Cannot find translation for source Spotify
Dec 15 22:19:54 volumio volumio[3298]: info: Disabling plugin upnp_browser
Dec 15 22:19:54 volumio volumio[3298]: info: Done.
Dec 15 22:19:55 volumio volumio[3298]: info: Disabling MyMusic plugin airplay_emulation
Dec 15 22:19:55 volumio volumio[3298]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesShairport-Sync
Dec 15 22:19:55 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 15 22:19:55 volumio volumio[3298]: Cannot find translation for source Spotify
Dec 15 22:19:55 volumio volumio[3298]: info: Disabling plugin airplay_emulation
Dec 15 22:19:55 volumio volumio[3298]: info: Done.
Dec 15 22:19:55 volumio sudo[3864]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop shairport-sync
Dec 15 22:19:55 volumio sudo[3864]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 22:19:55 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Dec 15 22:19:55 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Dec 15 22:19:55 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Dec 15 22:19:55 volumio systemd[1]: shairport-sync.service: Consumed 1.918s CPU time.
Dec 15 22:19:56 volumio sudo[3864]: pam_unix(sudo:session): session closed for user root
Dec 15 22:19:56 volumio volumio[3298]: info: Shairport-Sync Stopped
Dec 15 22:19:56 volumio volumio[3298]: info: Disabling MyMusic plugin upnp
Dec 15 22:19:56 volumio sudo[3881]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service
Dec 15 22:19:56 volumio sudo[3881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Dec 15 22:19:56 volumio systemd[1]: Stopping upmpdcli.service - UPnP Renderer front-end to MPD...
Dec 15 22:19:57 volumio volumio[3298]: Upnp client error: Error: read ECONNRESET
Dec 15 22:19:57 volumio systemd[1]: upmpdcli.service: Deactivated successfully.
Dec 15 22:19:57 volumio systemd[1]: Stopped upmpdcli.service - UPnP Renderer front-end to MPD.
Dec 15 22:19:57 volumio volumio[3298]: Upnp client error: Error: read ECONNRESET
Dec 15 22:19:57 volumio sudo[3881]: pam_unix(sudo:session): session closed for user root
Dec 15 22:19:57 volumio volumio[3298]: info: Disabling plugin upnp
Dec 15 22:19:57 volumio volumio[3298]: info: Done.
Dec 15 22:19:58 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Dec 15 22:20:02 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Dec 15 22:20:06 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Dec 15 22:20:10 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Dec 15 22:20:14 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Dec 15 22:20:18 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Dec 15 22:20:19 volumio go-librespot[3689]: time="2025-12-15T22:20:19+05:30" level=trace msg="sent dealer ping"
Dec 15 22:20:19 volumio go-librespot[3689]: time="2025-12-15T22:20:19+05:30" level=trace msg="received dealer pong"
Dec 15 22:20:22 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Dec 15 22:20:25 volumio volumio[3298]: info: CALLMETHOD: miscellanea my_music updateMusicLibraryBrowseSourcesVisibility [object Object]
Dec 15 22:20:25 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: my_music , updateMusicLibraryBrowseSourcesVisibility
Dec 15 22:20:25 volumio volumio[3298]: info: CoreCommandRouter::volumioUpdateToBrowseSources
Dec 15 22:20:25 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Dec 15 22:20:25 volumio volumio[3298]: Cannot find translation for source Spotify
Dec 15 22:20:26 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Dec 15 22:20:30 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Dec 15 22:20:34 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats
Dec 15 22:20:35 volumio volumio[3298]: info: CoreCommandRouter::volumioGetState
Dec 15 22:20:35 volumio volumio[3298]: info: CorePlayQueue::getTrack 0
Dec 15 22:20:38 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Dec 15 22:20:38 volumio volumio[3298]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Dec 15 22:20:42 volumio volumio[3298]: info: CoreCommandRouter::getUIConfigOnPlugin
Dec 15 22:20:49 volumio go-librespot[3689]: time="2025-12-15T22:20:49+05:30" level=trace msg="received accesspoint ping"
Dec 15 22:20:49 volumio go-librespot[3689]: time="2025-12-15T22:20:49+05:30" level=trace msg="received accesspoint pong ack"
Dec 15 22:20:49 volumio go-librespot[3689]: time="2025-12-15T22:20:49+05:30" level=trace msg="sent dealer ping"
Dec 15 22:20:50 volumio go-librespot[3689]: time="2025-12-15T22:20:50+05:30" level=trace msg="received dealer pong"
Dec 15 22:20:52 volumio volumio[3298]: error: [ytcr] Failed to obtain manual pairing code: timeout.
Dec 15 22:20:52 volumio volumio[3298]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 15 22:20:52 volumio volumio[3298]: ConnectionError: Connection error in fetching pairing code
Dec 15 22:20:52 volumio volumio[3298]: at PairingCodeRequestService._PairingCodeRequestService_getCodeAndEmit (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/PairingCodeRequestService.js:126:17)
Dec 15 22:20:52 volumio volumio[3298]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5) {
Dec 15 22:20:52 volumio volumio[3298]: cause: TypeError: fetch failed
Dec 15 22:20:52 volumio volumio[3298]: at Object.fetch (node:internal/deps/undici/undici:11576:11)
Dec 15 22:20:52 volumio volumio[3298]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Dec 15 22:20:52 volumio volumio[3298]: at async PairingCodeRequestService._PairingCodeRequestService_getCodeAndEmit (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/lib/app/PairingCodeRequestService.js:120:20) {
Dec 15 22:20:52 volumio volumio[3298]: cause: ConnectTimeoutError: Connect Timeout Error
Dec 15 22:20:52 volumio volumio[3298]: at onConnectTimeout (node:internal/deps/undici/undici:8522:28)
Dec 15 22:20:52 volumio volumio[3298]: at node:internal/deps/undici/undici:8480:50
Dec 15 22:20:52 volumio volumio[3298]: at Immediate._onImmediate (node:internal/deps/undici/undici:8511:13)
Dec 15 22:20:52 volumio volumio[3298]: at process.processImmediate (node:internal/timers:478:21) {
Dec 15 22:20:52 volumio volumio[3298]: code: 'UND_ERR_CONNECT_TIMEOUT'
Dec 15 22:20:52 volumio volumio[3298]: }
Dec 15 22:20:52 volumio volumio[3298]: },
Dec 15 22:20:52 volumio volumio[3298]: info: {
Dec 15 22:20:52 volumio volumio[3298]: url: 'https://www.youtube.com/api/lounge/pairing/get_pairing_code?ctx=pair'
Dec 15 22:20:52 volumio volumio[3298]: }
Dec 15 22:20:52 volumio volumio[3298]: }
Dec 15 22:20:52 volumio volumio[3298]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Dec 15 22:20:52 volumio sudo[3983]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 22:19'
Dec 15 22:20:52 volumio sudo[3983]: 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="cfdc872d40b979cca36352a7333c940c38dc64b5"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025"
VOLUMIO_VERSION="4.073"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"