Jan 10 13:42:16 volumio bluealsa[1269]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Jan 10 13:42:16 volumio bluealsa[1269]: ../src/ba-transport.c:319: New A2DP transport: 15 Jan 10 13:42:16 volumio bluealsa[1269]: ../src/ba-transport.c:320: A2DP socket MTU: 15: R:1021 W:1024 Jan 10 13:42:16 volumio bluealsa[1269]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Jan 10 13:42:16 volumio volumio[1646]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: true from C0:7A:D6:94:2E:5A Jan 10 13:42:16 volumio volumio[1646]: ------------------------------------ BT MESSAGE: Playback started, enabling output Jan 10 13:42:16 volumio volumio[1646]: info: CoreCommandRouter::volumioStop Jan 10 13:42:16 volumio bluealsa[1269]: ../src/ba-transport.c:1075: Starting transport: A2DP Sink (SBC) Jan 10 13:42:16 volumio volumio[1646]: info: CoreStateMachine::stop Jan 10 13:42:16 volumio volumio[1646]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 10 13:42:16 volumio volumio[1646]: info: CoreStateMachine::stPlaybackTimer Jan 10 13:42:16 volumio volumio[1646]: info: CoreStateMachine::updateTrackBlock Jan 10 13:42:16 volumio volumio[1646]: info: CorePlayQueue::getTrackBlock Jan 10 13:42:16 volumio volumio[1646]: info: CoreStateMachine::pushState Jan 10 13:42:16 volumio volumio[1646]: info: CorePlayQueue::getTrack 0 Jan 10 13:42:16 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 13:42:16 volumio volumio[1646]: info: CoreCommandRouter::volumioPushState Jan 10 13:42:16 volumio bluealsa[1269]: ../src/ba-transport-pcm.c:294: Created BT socket duplicate: [15]: 16 Jan 10 13:42:16 volumio bluealsa[1269]: ../src/ba-transport-pcm.c:373: Created new IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Jan 10 13:42:16 volumio bluealsa[1269]: ../src/a2dp-sbc.c:331: PCM IO loop: START: a2dp_sbc_dec_thread: A2DP Sink (SBC) Jan 10 13:42:16 volumio volumio[1646]: info: MRS: Pushing multiroomSync output update for this device Jan 10 13:42:16 volumio volumio[1646]: info: MRS: Pushing multiroomSync output Jan 10 13:42:16 volumio volumio[1646]: info: CoreCommandRouter::volumioGetState Jan 10 13:42:16 volumio volumio[1646]: info: CorePlayQueue::getTrack 0 Jan 10 13:42:16 volumio volumio[1646]: info: CoreStateMachine::serviceStop Jan 10 13:42:16 volumio volumio[1646]: info: CorePlayQueue::getTrack 0 Jan 10 13:42:16 volumio volumio[1646]: info: CoreCommandRouter::serviceStop Jan 10 13:42:16 volumio volumio[1646]: info: [1768048936031] ControllerWebradio::stop Jan 10 13:42:16 volumio volumio[1646]: verbose: ControllerMpd::sendMpdCommand stop Jan 10 13:42:16 volumio volumio[1646]: info: touch_display: Setting screensaver timeout to 120 seconds. Jan 10 13:42:16 volumio volumio[1646]: info: Jan 10 13:42:16 volumio volumio[1646]: ---------------------------- MPD announces state update: player Jan 10 13:42:16 volumio volumio[1646]: info: sendMpdCommand stop took 24 milliseconds Jan 10 13:42:16 volumio volumio[1646]: info: ControllerMpd::getState Jan 10 13:42:16 volumio volumio[1646]: verbose: ControllerMpd::sendMpdCommand status Jan 10 13:42:16 volumio volumio[1646]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput Jan 10 13:42:16 volumio volumio[1646]: ------------------------------------ BT MESSAGE: [AAMP] Modular pipeline enabled - using default ALSA route: volumio Jan 10 13:42:16 volumio bluetoothd[990]: Path / reserved for Adv Monitor app :1.45 Jan 10 13:42:16 volumio bluetoothd[990]: Adv Monitor app :1.45 disconnected from D-Bus Jan 10 13:42:16 volumio volumio[1646]: ------------------------------------ BT MESSAGE: Detected connected BT MAC: C0:7A:D6:94:2E:5A Jan 10 13:42:16 volumio volumio[1646]: ------------------------------------ BT MESSAGE: Spawning bluealsa-aplay with args: --profile-a2dp --pcm=volumio --pcm-buffer-time=500000 --pcm-period-time=100000 C0:7A:D6:94:2E:5A Jan 10 13:42:16 volumio volumio[1646]: ------------------------------------ BT MESSAGE: [metaCache] Loaded metadata for C0:7A:D6:94:2E:5A from memory Jan 10 13:42:16 volumio volumio[1646]: ------------------------------------ BT MESSAGE: Loaded metadata from cache for C0:7A:D6:94:2E:5A Jan 10 13:42:16 volumio volumio[1646]: info: sendMpdCommand status took 41 milliseconds Jan 10 13:42:16 volumio volumio[1646]: verbose: ControllerMpd::parseState Jan 10 13:42:16 volumio volumio[1646]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 10 13:42:16 volumio volumio[1646]: info: sendMpdCommand playlistinfo took 3 milliseconds Jan 10 13:42:16 volumio volumio[1646]: verbose: ControllerMpd::parseTrackInfo Jan 10 13:42:16 volumio volumio[1646]: info: ControllerMpd::pushState Jan 10 13:42:16 volumio volumio[1646]: info: CoreCommandRouter::servicePushState Jan 10 13:42:16 volumio volumio[1646]: info: CoreStateMachine::pushState Jan 10 13:42:16 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 13:42:16 volumio volumio[1646]: info: CoreCommandRouter::volumioPushState Jan 10 13:42:16 volumio volumio[1646]: info: MRS: Pushing multiroomSync output update for this device Jan 10 13:42:16 volumio volumio[1646]: info: MRS: Pushing multiroomSync output Jan 10 13:42:16 volumio volumio[1646]: info: CoreCommandRouter::volumioGetState Jan 10 13:42:16 volumio volumio[1646]: info: CorePlayQueue::getTrack 0 Jan 10 13:42:16 volumio volumio[1646]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Jan 10 13:42:16 volumio bluealsa[1269]: ../src/dbus.c:47: Called: org.bluealsa.PCM1.Open() on /org/bluealsa/hci0/dev_C0_7A_D6_94_2E_5A/a2dpsnk/source Jan 10 13:42:16 volumio volumio[1646]: info: ------------------------------ 53ms Jan 10 13:42:16 volumio volumio[1646]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [18201] D: aplay.c:904: Creating IO worker C0:7A:D6:94:2E:5A Jan 10 13:42:16 volumio volumio[1646]: bluealsa-aplay: [18201] D: aplay.c:1320: Starting main loop Jan 10 13:42:16 volumio volumio[1646]: bluealsa-aplay: [18202] D: aplay.c:577: Opening BlueALSA source PCM: /org/bluealsa/hci0/dev_C0_7A_D6_94_2E_5A/a2dpsnk/source Jan 10 13:42:16 volumio volumio[1646]: bluealsa-aplay: [18202] D: aplay.c:603: Starting IO loop Jan 10 13:42:16 volumio bluealsa[1269]: ../src/codec-sbc.c:278: SBC setup: 44100 Hz JointStereo allocation=Loudness blocks=16 sub-bands=8 bit-pool=53 => 327993 bps Jan 10 13:42:16 volumio volumio[1646]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [18202] D: aplay.c:732: Opening ALSA playback PCM: name=volumio channels=2 rate=44100 Jan 10 13:42:16 volumio volumio[1646]: ------------------------------------ BT MESSAGE: Seek received post-resume, pushing metadata Jan 10 13:42:16 volumio volumio[1646]: info: CoreCommandRouter::servicePushState Jan 10 13:42:16 volumio volumio[1646]: info: CoreStateMachine::pushState Jan 10 13:42:16 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 13:42:16 volumio volumio[1646]: info: CoreCommandRouter::volumioPushState Jan 10 13:42:16 volumio volumio[1646]: info: MRS: Pushing multiroomSync output update for this device Jan 10 13:42:16 volumio volumio[1646]: info: MRS: Pushing multiroomSync output Jan 10 13:42:16 volumio volumio[1646]: info: CoreCommandRouter::volumioGetState Jan 10 13:42:16 volumio volumio[1646]: info: touch_display: Setting screensaver timeout to 0 seconds. Jan 10 13:42:16 volumio volumio[1646]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [18202] D: aplay.c:339: Opening ALSA mixer: name=default elem=Master index=0 Jan 10 13:42:16 volumio volumio[1646]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [18202] W: aplay.c:350: Couldn't open ALSA mixer: Mixer element not found Jan 10 13:42:20 volumio bluealsa[1269]: bluez.c:1480: Signal: org.freedesktop.DBus.Properties.PropertiesChanged(): org.bluez.MediaTransport1: State Jan 10 13:42:20 volumio bluealsa[1269]: ../src/ba-transport-pcm.c:307: Closing BT socket duplicate [15]: 16 Jan 10 13:42:20 volumio bluealsa[1269]: ../src/ba-transport.c:381: Closing A2DP transport: 15 Jan 10 13:42:20 volumio bluealsa[1269]: ../src/ba-transport-pcm.c:257: Exiting IO thread [ba-a2dp-sbc]: A2DP Sink (SBC) Jan 10 13:42:20 volumio volumio[1646]: ------------------------------------ BT MESSAGE: [dbus-next] Playback state changed: false from C0:7A:D6:94:2E:5A Jan 10 13:42:20 volumio volumio[1646]: ------------------------------------ BT MESSAGE: Received pause signal, scheduling idle check Jan 10 13:42:20 volumio volumio[1646]: info: CoreCommandRouter::servicePushState Jan 10 13:42:20 volumio volumio[1646]: info: CoreStateMachine::pushState Jan 10 13:42:20 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 10 13:42:20 volumio volumio[1646]: info: CoreCommandRouter::volumioPushState Jan 10 13:42:20 volumio volumio[1646]: info: MRS: Pushing multiroomSync output update for this device Jan 10 13:42:20 volumio volumio[1646]: info: MRS: Pushing multiroomSync output Jan 10 13:42:20 volumio volumio[1646]: info: CoreCommandRouter::volumioGetState Jan 10 13:42:20 volumio volumio[1646]: info: touch_display: Setting screensaver timeout to 120 seconds. Jan 10 13:42:20 volumio volumio[1646]: ------------------------------------ BT MESSAGE: bluealsa-aplay stderr: bluealsa-aplay: [18202] D: aplay.c:643: BT device marked as inactive: C0:7A:D6:94:2E:5A Jan 10 13:43:05 volumio sudo[18407]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 10 13:43:05 volumio sudo[18407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 13:43:05 volumio sudo[18407]: pam_unix(sudo:session): session closed for user root Jan 10 13:43:05 volumio sudo[18409]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 10 13:43:05 volumio sudo[18409]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 13:43:05 volumio sudo[18409]: pam_unix(sudo:session): session closed for user root Jan 10 13:43:05 volumio volumio[1646]: verbose: New Socket.io Connection to 192.168.168.20 from 192.168.168.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Jan 10 13:43:05 volumio sudo[18413]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 10 13:43:05 volumio sudo[18413]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 13:43:05 volumio sudo[18413]: pam_unix(sudo:session): session closed for user root Jan 10 13:43:05 volumio sudo[18415]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 10 13:43:05 volumio sudo[18415]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 10 13:43:05 volumio sudo[18415]: pam_unix(sudo:session): session closed for user root Jan 10 13:43:06 volumio volumio[1646]: verbose: New Socket.io Connection to 192.168.168.20 from 192.168.168.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/143.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Jan 10 13:43:06 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 10 13:43:06 volumio volumio[1646]: info: CoreCommandRouter::volumioGetVisibleSources Jan 10 13:43:06 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 10 13:43:06 volumio volumio[1646]: info: CoreCommandRouter::volumioGetState Jan 10 13:43:06 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 10 13:43:06 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 10 13:43:06 volumio volumio[1646]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jan 10 13:43:06 volumio volumio[1646]: info: Received Get System Info Jan 10 13:43:06 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 13:43:06 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 13:43:06 volumio volumio[1646]: info: Discovery: Getting this device information Jan 10 13:43:06 volumio volumio[1646]: info: CoreCommandRouter::volumioGetState Jan 10 13:43:06 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 13:43:06 volumio volumio[1646]: info: CoreCommandRouter::volumioGetState Jan 10 13:43:06 volumio volumio[1646]: info: Listing playlists Jan 10 13:43:06 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Jan 10 13:43:06 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jan 10 13:43:06 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jan 10 13:43:06 volumio volumio[1646]: An internal error occurred while serving an albumart. Details: NotFoundError: Not Found Jan 10 13:43:06 volumio volumio[1646]: at createHttpError (/volumio/node_modules/send/index.js:979:12) Jan 10 13:43:06 volumio volumio[1646]: at SendStream.error (/volumio/node_modules/send/index.js:270:31) Jan 10 13:43:06 volumio volumio[1646]: at SendStream.pipe (/volumio/node_modules/send/index.js:580:14) Jan 10 13:43:06 volumio volumio[1646]: at sendfile (/volumio/node_modules/express/lib/response.js:1139:8) Jan 10 13:43:06 volumio volumio[1646]: at ServerResponse.sendFile (/volumio/node_modules/express/lib/response.js:450:3) Jan 10 13:43:06 volumio volumio[1646]: at Promise._failFn (/volumio/app/plugins/miscellanea/albumart/albumart.js:449:13) Jan 10 13:43:06 volumio volumio[1646]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Jan 10 13:43:06 volumio volumio[1646]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Jan 10 13:43:07 volumio volumio[1646]: info: CoreCommandRouter::volumioGetState Jan 10 13:43:07 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Jan 10 13:43:07 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 13:43:07 volumio volumio[1646]: info: Received Get System Info Jan 10 13:43:07 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 13:43:07 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 13:43:07 volumio volumio[1646]: info: Discovery: Getting this device information Jan 10 13:43:07 volumio volumio[1646]: info: CoreCommandRouter::volumioGetState Jan 10 13:43:07 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 13:43:08 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jan 10 13:43:08 volumio volumio[1646]: info: Received Get System Info Jan 10 13:43:08 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 10 13:43:08 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 10 13:43:08 volumio volumio[1646]: info: Discovery: Getting this device information Jan 10 13:43:08 volumio volumio[1646]: info: CoreCommandRouter::volumioGetState Jan 10 13:43:08 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 10 13:43:09 volumio volumio[1646]: info: Executing endpoint metavolumio Jan 10 13:43:09 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 10 13:43:09 volumio volumio[1646]: info: Executing endpoint metavolumio Jan 10 13:43:09 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 10 13:43:09 volumio volumio[1646]: info: Executing endpoint metavolumio Jan 10 13:43:09 volumio volumio[1646]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Jan 10 13:43:09 volumio volumio[1646]: info: CoreCommandRouter::volumioGetQueue Jan 10 13:43:09 volumio volumio[1646]: info: CoreStateMachine::getQueue Jan 10 13:43:09 volumio volumio[1646]: info: CorePlayQueue::getQueue Jan 10 13:43:13 volumio volumio[1646]: info: CoreCommandRouter::volumioRemoveQueueItem Jan 10 13:43:13 volumio volumio[1646]: info: CoreStateMachine::removeQueueItem Jan 10 13:43:13 volumio volumio[1646]: info: CoreStateMachine::stop Jan 10 13:43:13 volumio volumio[1646]: info: CoreStateMachine::serviceStop Jan 10 13:43:13 volumio volumio[1646]: info: CoreCommandRouter::serviceStop Jan 10 13:43:13 volumio volumio[1646]: error: WARNING: No stop method for service [object Object] Jan 10 13:43:13 volumio volumio[1646]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 10 13:43:13 volumio volumio[1646]: TypeError: Cannot read properties of undefined (reading 'then') Jan 10 13:43:13 volumio volumio[1646]: at CoreStateMachine.removeQueueItem (/volumio/app/statemachine.js:1372:7) Jan 10 13:43:13 volumio volumio[1646]: at CoreCommandRouter.volumioRemoveQueueItem (/volumio/app/index.js:121:28) Jan 10 13:43:13 volumio volumio[1646]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:173:33) Jan 10 13:43:13 volumio volumio[1646]: at Socket.emit (node:events:514:28) Jan 10 13:43:13 volumio volumio[1646]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Jan 10 13:43:13 volumio volumio[1646]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) Jan 10 13:43:13 volumio volumio[1646]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 10 13:43:13 volumio sudo[18462]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-10 13:42' Jan 10 13:43:13 volumio sudo[18462]: 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"