-- Logs begin at Thu 2019-02-14 14:11:58 +04, end at Sat 2025-07-19 09:54:12 +04. -- Jul 19 09:53:00 volumio-pi4l go-librespot[1451]: time="2025-07-19T09:53:00+04:00" level=trace msg="sent dealer ping" Jul 19 09:53:00 volumio-pi4l go-librespot[1451]: time="2025-07-19T09:53:00+04:00" level=trace msg="received dealer pong" Jul 19 09:53:01 volumio-pi4l vtcs[14468]: [start:106] Entering Jul 19 09:53:01 volumio-pi4l vtcs[14468]: [start:113] Reopening PCM device... Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: CoreCommandRouter::servicePushState Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: CoreStateMachine::pushState Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: CoreCommandRouter::volumioPushState Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: MRS: Pushing multiroomSync output update for this device Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: MRS: Pushing multiroomSync output Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: CoreCommandRouter::volumioGetState Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Jul 19 09:53:01 volumio-pi4l volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 19 09:53:01 volumio-pi4l sudo[15964]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Jul 19 09:53:01 volumio-pi4l sudo[15964]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 19 09:53:01 volumio-pi4l vtcs[14468]: [start:115] PCM opened successfully. Jul 19 09:53:01 volumio-pi4l vtcs[14468]: [start:120] Exiting Jul 19 09:53:01 volumio-pi4l vtcs[14468]: [feedThread:223] Entering Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: touch_display: Setting screensaver timeout to 0 seconds. Jul 19 09:53:01 volumio-pi4l systemd[1]: Started peppymeterbasic Daemon. Jul 19 09:53:01 volumio-pi4l sudo[15964]: pam_unix(sudo:session): session closed for user root Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: peppymeterbasic Daemon Started Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: CoreCommandRouter::servicePushState Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: CoreStateMachine::pushState Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: CoreCommandRouter::volumioPushState Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: MRS: Pushing multiroomSync output update for this device Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: MRS: Pushing multiroomSync output Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: CoreCommandRouter::volumioGetState Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Jul 19 09:53:01 volumio-pi4l volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 19 09:53:01 volumio-pi4l sudo[15973]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Jul 19 09:53:01 volumio-pi4l sudo[15973]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 19 09:53:01 volumio-pi4l sudo[15973]: pam_unix(sudo:session): session closed for user root Jul 19 09:53:01 volumio-pi4l volumio[1186]: info: peppymeterbasic Daemon Started Jul 19 09:53:08 volumio-pi4l wpa_supplicant[952]: wlan0: Failed to initiate sched scan Jul 19 09:53:19 volumio-pi4l wpa_supplicant[952]: wlan0: Failed to initiate sched scan Jul 19 09:53:21 volumio-pi4l systemd[1]: peppymeterbasic.service: Succeeded. Jul 19 09:53:27 volumio-pi4l volumiologrotate[633]: ls: cannot access '/var/log/samba/log.wb-VOLUMIO': No such file or directory Jul 19 09:53:27 volumio-pi4l volumiologrotate[633]: ls: cannot access 'PI4L': No such file or directory Jul 19 09:53:30 volumio-pi4l go-librespot[1451]: time="2025-07-19T09:53:30+04:00" level=trace msg="sent dealer ping" Jul 19 09:53:30 volumio-pi4l wpa_supplicant[952]: wlan0: Failed to initiate sched scan Jul 19 09:53:32 volumio-pi4l go-librespot[1451]: time="2025-07-19T09:53:32+04:00" level=trace msg="received dealer pong" Jul 19 09:53:34 volumio-pi4l ntpd[821]: Soliciting pool server 2001:ac8:81:65:0:2:0:2 Jul 19 09:53:36 volumio-pi4l vtcs[14468]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:765:(_snd_pcm_volumioswitch_transfer_wrap) PCM volumioMultiRoomServer cannot write to the the target pcm peppy_in as no mmap space is available. 2014 frames were written Jul 19 09:53:36 volumio-pi4l vtcs[14468]: ALSA lib /home/pi/volumio-alsa-plugin/src/pcm_volumioswitch.c:818:(_snd_pcm_volumioswitch_transfer_wrap) PCM volumioMultiRoomServer has not transferred a full period to the target pcm peppy_in. 2014 frames were written Jul 19 09:53:36 volumio-pi4l vtcs[14468]: ALSA lib pcm.c:8427:(snd_pcm_recover) cannot recovery from underrun, prepare failed: Device or resource busy Jul 19 09:53:36 volumio-pi4l vtcs[14468]: [feedThread:265] ALSA error: Device or resource busy Jul 19 09:53:36 volumio-pi4l vtcs[14468]: [feedThread:276] Exiting Jul 19 09:53:39 volumio-pi4l volumio[1186]: info: CoreCommandRouter::servicePushState Jul 19 09:53:39 volumio-pi4l volumio[1186]: info: CoreStateMachine::pushState Jul 19 09:53:39 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 19 09:53:39 volumio-pi4l volumio[1186]: info: CoreCommandRouter::volumioPushState Jul 19 09:53:39 volumio-pi4l vtcs[14468]: [pause:147] Entering Jul 19 09:53:39 volumio-pi4l volumio[1186]: info: MRS: Pushing multiroomSync output update for this device Jul 19 09:53:39 volumio-pi4l volumio[1186]: info: MRS: Pushing multiroomSync output Jul 19 09:53:39 volumio-pi4l volumio[1186]: info: CoreCommandRouter::volumioGetState Jul 19 09:53:39 volumio-pi4l volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status pause Jul 19 09:53:39 volumio-pi4l vtcs[14468]: [pause:161] Exiting Jul 19 09:53:39 volumio-pi4l volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 19 09:53:39 volumio-pi4l sudo[16089]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppymeterbasic.service Jul 19 09:53:39 volumio-pi4l sudo[16089]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 19 09:53:39 volumio-pi4l volumio[1186]: info: touch_display: Setting screensaver timeout to 60 seconds. Jul 19 09:53:39 volumio-pi4l sudo[16089]: pam_unix(sudo:session): session closed for user root Jul 19 09:53:39 volumio-pi4l volumio[1186]: info: peppymeterbasic Daemon Stop Jul 19 09:53:41 volumio-pi4l wpa_supplicant[952]: wlan0: Failed to initiate sched scan Jul 19 09:53:42 volumio-pi4l vtcs[14468]: [start:106] Entering Jul 19 09:53:42 volumio-pi4l vtcs[14468]: [start:113] Reopening PCM device... Jul 19 09:53:42 volumio-pi4l volumio[1186]: info: CoreCommandRouter::servicePushState Jul 19 09:53:42 volumio-pi4l volumio[1186]: info: CoreStateMachine::pushState Jul 19 09:53:42 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 19 09:53:42 volumio-pi4l volumio[1186]: info: CoreCommandRouter::volumioPushState Jul 19 09:53:42 volumio-pi4l volumio[1186]: info: MRS: Pushing multiroomSync output update for this device Jul 19 09:53:42 volumio-pi4l volumio[1186]: info: MRS: Pushing multiroomSync output Jul 19 09:53:42 volumio-pi4l volumio[1186]: info: CoreCommandRouter::volumioGetState Jul 19 09:53:42 volumio-pi4l volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Jul 19 09:53:42 volumio-pi4l volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 19 09:53:42 volumio-pi4l sudo[16096]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Jul 19 09:53:42 volumio-pi4l sudo[16096]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 19 09:53:42 volumio-pi4l vtcs[14468]: [start:115] PCM opened successfully. Jul 19 09:53:42 volumio-pi4l vtcs[14468]: [start:120] Exiting Jul 19 09:53:42 volumio-pi4l vtcs[14468]: [feedThread:223] Entering Jul 19 09:53:42 volumio-pi4l volumio[1186]: info: touch_display: Setting screensaver timeout to 0 seconds. Jul 19 09:53:42 volumio-pi4l systemd[1]: Started peppymeterbasic Daemon. Jul 19 09:53:42 volumio-pi4l sudo[16096]: pam_unix(sudo:session): session closed for user root Jul 19 09:53:42 volumio-pi4l volumio[1186]: info: peppymeterbasic Daemon Started Jul 19 09:53:43 volumio-pi4l volumio[1186]: info: CoreCommandRouter::servicePushState Jul 19 09:53:43 volumio-pi4l volumio[1186]: info: CoreStateMachine::pushState Jul 19 09:53:43 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 19 09:53:43 volumio-pi4l volumio[1186]: info: CoreCommandRouter::volumioPushState Jul 19 09:53:43 volumio-pi4l volumio[1186]: info: MRS: Pushing multiroomSync output update for this device Jul 19 09:53:43 volumio-pi4l volumio[1186]: info: MRS: Pushing multiroomSync output Jul 19 09:53:43 volumio-pi4l volumio[1186]: info: CoreCommandRouter::volumioGetState Jul 19 09:53:43 volumio-pi4l volumio[1186]: info: PeppyMeterBasic ---peppymeterbasic status play Jul 19 09:53:43 volumio-pi4l volumio[1186]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jul 19 09:53:43 volumio-pi4l sudo[16108]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start peppymeterbasic.service Jul 19 09:53:43 volumio-pi4l sudo[16108]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 19 09:53:43 volumio-pi4l sudo[16108]: pam_unix(sudo:session): session closed for user root Jul 19 09:53:43 volumio-pi4l volumio[1186]: info: peppymeterbasic Daemon Started Jul 19 09:53:49 volumio-pi4l systemd[1]: peppymeterbasic.service: Succeeded. Jul 19 09:53:53 volumio-pi4l wpa_supplicant[952]: wlan0: Failed to initiate sched scan Jul 19 09:53:56 volumio-pi4l volumio[1186]: verbose: New Socket.io Connection to 192.168.3.136 from 192.168.3.24 UA: Mozilla/5.0 (Linux; Android 15; SM-S918B Build/AP3A.240905.015.A2; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/138.0.7204.67 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 12 Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: CoreCommandRouter::volumioGetVisibleSources Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: CoreCommandRouter::volumioGetState Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: Received Get System Info Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: Discovery: Getting this device information Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: CoreCommandRouter::volumioGetState Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: CoreCommandRouter::volumioGetState Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: Listing playlists Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: CoreCommandRouter::volumioGetQueue Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: CoreStateMachine::getQueue Jul 19 09:53:56 volumio-pi4l volumio[1186]: info: CorePlayQueue::getQueue Jul 19 09:53:57 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Jul 19 09:54:00 volumio-pi4l go-librespot[1451]: time="2025-07-19T09:54:00+04:00" level=trace msg="sent dealer ping" Jul 19 09:54:00 volumio-pi4l go-librespot[1451]: time="2025-07-19T09:54:00+04:00" level=trace msg="received dealer pong" Jul 19 09:54:01 volumio-pi4l go-librespot[1451]: time="2025-07-19T09:54:01+04:00" level=trace msg="received accesspoint ping" Jul 19 09:54:01 volumio-pi4l go-librespot[1451]: time="2025-07-19T09:54:01+04:00" level=trace msg="received accesspoint pong ack" Jul 19 09:54:03 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jul 19 09:54:03 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jul 19 09:54:04 volumio-pi4l wpa_supplicant[952]: wlan0: Failed to initiate sched scan Jul 19 09:54:05 volumio-pi4l volumio[1186]: verbose: New Socket.io Connection to 192.168.3.136:3000 from 192.168.3.24 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 13 Jul 19 09:54:05 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jul 19 09:54:05 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jul 19 09:54:05 volumio-pi4l volumio[1186]: info: Discovery: Getting this device information Jul 19 09:54:05 volumio-pi4l volumio[1186]: info: CoreCommandRouter::volumioGetState Jul 19 09:54:05 volumio-pi4l volumio[1186]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jul 19 09:54:11 volumio-pi4l volumio[1186]: info: Stopping peppymeterbasic service Jul 19 09:54:11 volumio-pi4l volumio[1186]: info: CoreStateMachine::stop Jul 19 09:54:11 volumio-pi4l volumio[1186]: info: CoreStateMachine::serviceStop Jul 19 09:54:11 volumio-pi4l volumio[1186]: info: CoreCommandRouter::serviceStop Jul 19 09:54:11 volumio-pi4l vtcs[14468]: [close:85] Entering Jul 19 09:54:11 volumio-pi4l volumio[1186]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 19 09:54:11 volumio-pi4l volumio[1186]: TypeError: Cannot read property 'then' of undefined Jul 19 09:54:11 volumio-pi4l volumio[1186]: at peppymeterbasic.onStop (/data/plugins/user_interface/peppymeterbasic/index.js:60:43) Jul 19 09:54:11 volumio-pi4l volumio[1186]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Jul 19 09:54:11 volumio-pi4l volumio[1186]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1883:8) Jul 19 09:54:11 volumio-pi4l volumio[1186]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1556:29) Jul 19 09:54:11 volumio-pi4l volumio[1186]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1401:47) Jul 19 09:54:11 volumio-pi4l volumio[1186]: at Socket.emit (events.js:315:20) Jul 19 09:54:11 volumio-pi4l volumio[1186]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jul 19 09:54:11 volumio-pi4l volumio[1186]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Jul 19 09:54:11 volumio-pi4l volumio[1186]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 19 09:54:11 volumio-pi4l vtcs[14468]: [feedThread:276] Exiting Jul 19 09:54:11 volumio-pi4l vtcs[14468]: [close:100] Exiting Jul 19 09:54:11 volumio-pi4l vtcs[14468]: [2025-07-19 09:54:11] [info] asio async_shutdown error: asio.misc:2 (End of file) Jul 19 09:54:12 volumio-pi4l vtcs[14468]: [2025-07-19 09:54:12.146] [tisoc] [warning] [PlaybackControllerImpl.cpp:520] Illegal state:0 Jul 19 09:54:12 volumio-pi4l sudo[16175]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-19 09:53 Jul 19 09:54:12 volumio-pi4l sudo[16175]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster 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="a142ed2648fb91920de0dde3a60cd39b5d0ba4f6" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="811ff8312d42f9da0260be1d353081a805678820" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 02 Jul 2025 04:07:25 PM CEST" VOLUMIO_VERSION="3.819" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3b9115b1943141a9d7186aa434f8f3c2"