-- Logs begin at Thu 2019-02-14 05:11:58 EST, end at Sun 2025-05-04 14:02:18 EDT. -- May 04 14:01:23 volumio go-librespot[1188]: time="2025-05-04T14:01:23-04:00" level=trace msg="received accesspoint ping" May 04 14:01:23 volumio go-librespot[1188]: time="2025-05-04T14:01:23-04:00" level=trace msg="received accesspoint pong ack" May 04 14:01:24 volumio go-librespot[1188]: time="2025-05-04T14:01:24-04:00" level=trace msg="sent dealer ping" May 04 14:01:24 volumio go-librespot[1188]: time="2025-05-04T14:01:24-04:00" level=trace msg="received dealer pong" May 04 14:01:30 volumio volumio[866]: info: Tunnel connection is inactive, restarting it May 04 14:01:30 volumio volumio[866]: info: Starting Tunnel 1 May 04 14:01:30 volumio volumio[866]: info: Starting Tunnel Connection Checker May 04 14:01:31 volumio sudo[1890]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service May 04 14:01:31 volumio sudo[1890]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 14:01:31 volumio autossh[1500]: received signal to exit (15) May 04 14:01:31 volumio systemd[1]: Stopping MyVolumio SSH Tunnel... May 04 14:01:31 volumio systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM May 04 14:01:31 volumio systemd[1]: sshtunnel.service: Succeeded. May 04 14:01:31 volumio systemd[1]: Stopped MyVolumio SSH Tunnel. May 04 14:01:31 volumio volumio[866]: ------------------------------------ BT MESSAGE: BT STATUS: running May 04 14:01:31 volumio volumio[866]: ------------------------------------ BT MESSAGE: BT STATUS: waiting May 04 14:01:31 volumio systemd[1]: Started MyVolumio SSH Tunnel. May 04 14:01:31 volumio sudo[1890]: pam_unix(sudo:session): session closed for user root May 04 14:01:31 volumio volumio[866]: info: Remote SSH Started May 04 14:01:31 volumio autossh[1893]: port set to 0, monitoring disabled May 04 14:01:31 volumio autossh[1893]: starting ssh (count 1) May 04 14:01:31 volumio autossh[1893]: ssh child pid is 1896 May 04 14:01:31 volumio volumio[866]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 10 May 04 14:01:31 volumio volumio[866]: info: CoreCommandRouter::volumioGetState May 04 14:01:31 volumio volumio[866]: info: CorePlayQueue::getTrack 0 May 04 14:01:31 volumio volumiossh-tunnel[1892]: Warning: Permanently added '[us3.myvolumio.org]:2222,[159.203.57.91]:2222' (RSA) to the list of known hosts. May 04 14:01:46 volumio volumio[866]: info: VolumeController::SetAlsaVolume94 May 04 14:01:46 volumio volumio[866]: info: CoreStateMachine::pushState May 04 14:01:46 volumio volumio[866]: info: CorePlayQueue::getTrack 0 May 04 14:01:46 volumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 14:01:46 volumio volumio[866]: info: CoreCommandRouter::volumioPushState May 04 14:01:46 volumio volumio[866]: info: MRS: Pushing multiroomSync output update for this device May 04 14:01:46 volumio volumio[866]: info: MRS: Pushing multiroomSync output May 04 14:01:46 volumio volumio[866]: info: [ASDebug] CurState: stop PrevState: stop May 04 14:01:46 volumio volumio[866]: info: PeppySpectrum ---peppyspectrum status stop May 04 14:01:46 volumio volumio[866]: SPOTIFY: RECEIVED VOLUMIO VOLUME 94 May 04 14:01:46 volumio volumio[866]: SPOTIFY: SPOTIFY VOLUME 100 May 04 14:01:46 volumio volumio[866]: SPOTIFY: VOLUMIO VOLUME 94 May 04 14:01:46 volumio volumio[866]: SPOTIFY: DELTA VOLUME ENOUGH: true May 04 14:01:46 volumio volumio[866]: info: Setting Spotify Volume from Volumio: 94 May 04 14:01:46 volumio sudo[1932]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 04 14:01:46 volumio sudo[1932]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 14:01:46 volumio sudo[1932]: pam_unix(sudo:session): session closed for user root May 04 14:01:46 volumio volumio[866]: info: peppyspectrum Daemon Stop May 04 14:01:47 volumio volumio[866]: SPOTIFY: SETTING SPOTIFY VOLUME 94 May 04 14:01:47 volumio volumio[866]: info: Sending Spotify command with payload to local API: /player/volume May 04 14:01:47 volumio go-librespot[1188]: time="2025-05-04T14:01:47-04:00" level=debug msg="update volume to 61602/65535" May 04 14:01:48 volumio volumio[866]: info: VolumeController::SetAlsaVolume98 May 04 14:01:48 volumio volumio[866]: info: CoreStateMachine::pushState May 04 14:01:48 volumio volumio[866]: info: CorePlayQueue::getTrack 0 May 04 14:01:48 volumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 14:01:48 volumio volumio[866]: info: CoreCommandRouter::volumioPushState May 04 14:01:48 volumio volumio[866]: info: MRS: Pushing multiroomSync output update for this device May 04 14:01:48 volumio volumio[866]: info: MRS: Pushing multiroomSync output May 04 14:01:48 volumio volumio[866]: info: [ASDebug] CurState: stop PrevState: stop May 04 14:01:48 volumio volumio[866]: info: PeppySpectrum ---peppyspectrum status stop May 04 14:01:48 volumio volumio[866]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 May 04 14:01:48 volumio volumio[866]: SPOTIFY: SPOTIFY VOLUME 94 May 04 14:01:48 volumio volumio[866]: SPOTIFY: VOLUMIO VOLUME 98 May 04 14:01:48 volumio volumio[866]: SPOTIFY: DELTA VOLUME ENOUGH: true May 04 14:01:48 volumio volumio[866]: info: Setting Spotify Volume from Volumio: 98 May 04 14:01:48 volumio sudo[1939]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 04 14:01:48 volumio sudo[1939]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 14:01:48 volumio sudo[1939]: pam_unix(sudo:session): session closed for user root May 04 14:01:48 volumio volumio[866]: info: peppyspectrum Daemon Stop May 04 14:01:49 volumio go-librespot[1188]: time="2025-05-04T14:01:49-04:00" level=debug msg="put connect state because VOLUME_CHANGED" May 04 14:01:49 volumio go-librespot[1188]: time="2025-05-04T14:01:49-04:00" level=trace msg="emitting websocket event: volume" May 04 14:01:49 volumio volumio[866]: SPOTIFY: received: {"type":"volume","data":{"value":94,"max":100}} May 04 14:01:49 volumio volumio[866]: SPOTIFY: RECEIVED SPOTIFY VOLUME 94 May 04 14:01:49 volumio volumio[866]: info: Setting Volumio Volume from Spotify: 94 May 04 14:01:49 volumio volumio[866]: info: VolumeController::SetAlsaVolume94 May 04 14:01:49 volumio volumio[866]: info: CoreStateMachine::pushState May 04 14:01:49 volumio volumio[866]: info: CorePlayQueue::getTrack 0 May 04 14:01:49 volumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 14:01:49 volumio volumio[866]: info: CoreCommandRouter::volumioPushState May 04 14:01:49 volumio volumio[866]: info: MRS: Pushing multiroomSync output update for this device May 04 14:01:49 volumio volumio[866]: info: MRS: Pushing multiroomSync output May 04 14:01:49 volumio volumio[866]: info: [ASDebug] CurState: stop PrevState: stop May 04 14:01:49 volumio volumio[866]: info: PeppySpectrum ---peppyspectrum status stop May 04 14:01:49 volumio volumio[866]: SPOTIFY: RECEIVED VOLUMIO VOLUME 94 May 04 14:01:49 volumio sudo[1943]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 04 14:01:49 volumio sudo[1943]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 14:01:49 volumio sudo[1943]: pam_unix(sudo:session): session closed for user root May 04 14:01:49 volumio volumio[866]: info: peppyspectrum Daemon Stop May 04 14:01:50 volumio volumio[866]: SPOTIFY: SETTING SPOTIFY VOLUME 98 May 04 14:01:50 volumio volumio[866]: info: Sending Spotify command with payload to local API: /player/volume May 04 14:01:50 volumio go-librespot[1188]: time="2025-05-04T14:01:50-04:00" level=debug msg="update volume to 64224/65535" May 04 14:01:51 volumio go-librespot[1188]: time="2025-05-04T14:01:51-04:00" level=debug msg="put connect state because VOLUME_CHANGED" May 04 14:01:51 volumio go-librespot[1188]: time="2025-05-04T14:01:51-04:00" level=trace msg="emitting websocket event: volume" May 04 14:01:51 volumio volumio[866]: SPOTIFY: received: {"type":"volume","data":{"value":98,"max":100}} May 04 14:01:51 volumio volumio[866]: SPOTIFY: RECEIVED SPOTIFY VOLUME 98 May 04 14:01:51 volumio volumio[866]: info: Setting Volumio Volume from Spotify: 98 May 04 14:01:51 volumio volumio[866]: info: VolumeController::SetAlsaVolume98 May 04 14:01:51 volumio volumio[866]: info: CoreStateMachine::pushState May 04 14:01:51 volumio volumio[866]: info: CorePlayQueue::getTrack 0 May 04 14:01:51 volumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 14:01:51 volumio volumio[866]: info: CoreCommandRouter::volumioPushState May 04 14:01:51 volumio volumio[866]: info: MRS: Pushing multiroomSync output update for this device May 04 14:01:51 volumio volumio[866]: info: MRS: Pushing multiroomSync output May 04 14:01:51 volumio volumio[866]: info: [ASDebug] CurState: stop PrevState: stop May 04 14:01:51 volumio volumio[866]: info: PeppySpectrum ---peppyspectrum status stop May 04 14:01:51 volumio volumio[866]: SPOTIFY: RECEIVED VOLUMIO VOLUME 98 May 04 14:01:51 volumio sudo[1961]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 04 14:01:51 volumio sudo[1961]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 14:01:51 volumio sudo[1961]: pam_unix(sudo:session): session closed for user root May 04 14:01:51 volumio volumio[866]: info: peppyspectrum Daemon Stop May 04 14:01:52 volumio volumio[866]: info: VolumeController::SetAlsaVolume99 May 04 14:01:53 volumio volumio[866]: info: CoreStateMachine::pushState May 04 14:01:53 volumio volumio[866]: info: CorePlayQueue::getTrack 0 May 04 14:01:53 volumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 14:01:53 volumio volumio[866]: info: CoreCommandRouter::volumioPushState May 04 14:01:53 volumio volumio[866]: info: MRS: Pushing multiroomSync output update for this device May 04 14:01:53 volumio volumio[866]: info: MRS: Pushing multiroomSync output May 04 14:01:53 volumio volumio[866]: info: [ASDebug] CurState: stop PrevState: stop May 04 14:01:53 volumio volumio[866]: info: PeppySpectrum ---peppyspectrum status stop May 04 14:01:53 volumio volumio[866]: SPOTIFY: RECEIVED VOLUMIO VOLUME 99 May 04 14:01:53 volumio volumio[866]: SPOTIFY: SPOTIFY VOLUME 98 May 04 14:01:53 volumio volumio[866]: SPOTIFY: VOLUMIO VOLUME 99 May 04 14:01:53 volumio volumio[866]: SPOTIFY: DELTA VOLUME ENOUGH: false May 04 14:01:53 volumio sudo[1966]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 04 14:01:53 volumio sudo[1966]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 14:01:53 volumio sudo[1966]: pam_unix(sudo:session): session closed for user root May 04 14:01:53 volumio volumio[866]: info: peppyspectrum Daemon Stop May 04 14:01:54 volumio go-librespot[1188]: time="2025-05-04T14:01:54-04:00" level=trace msg="sent dealer ping" May 04 14:01:54 volumio go-librespot[1188]: time="2025-05-04T14:01:54-04:00" level=trace msg="received dealer pong" May 04 14:01:54 volumio volumio[866]: info: VolumeController::SetAlsaVolume100 May 04 14:01:54 volumio volumio[866]: info: CoreStateMachine::pushState May 04 14:01:54 volumio volumio[866]: info: CorePlayQueue::getTrack 0 May 04 14:01:54 volumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 04 14:01:54 volumio volumio[866]: info: CoreCommandRouter::volumioPushState May 04 14:01:54 volumio volumio[866]: info: MRS: Pushing multiroomSync output update for this device May 04 14:01:54 volumio volumio[866]: info: MRS: Pushing multiroomSync output May 04 14:01:54 volumio volumio[866]: info: [ASDebug] CurState: stop PrevState: stop May 04 14:01:54 volumio volumio[866]: info: PeppySpectrum ---peppyspectrum status stop May 04 14:01:54 volumio volumio[866]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 04 14:01:54 volumio volumio[866]: SPOTIFY: SPOTIFY VOLUME 98 May 04 14:01:54 volumio volumio[866]: SPOTIFY: VOLUMIO VOLUME 100 May 04 14:01:54 volumio volumio[866]: SPOTIFY: DELTA VOLUME ENOUGH: true May 04 14:01:54 volumio volumio[866]: info: Setting Spotify Volume from Volumio: 100 May 04 14:01:54 volumio sudo[1970]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop peppyspectrum.service May 04 14:01:54 volumio sudo[1970]: pam_unix(sudo:session): session opened for user root by (uid=0) May 04 14:01:54 volumio sudo[1970]: pam_unix(sudo:session): session closed for user root May 04 14:01:54 volumio volumio[866]: info: peppyspectrum Daemon Stop May 04 14:01:56 volumio volumio[866]: SPOTIFY: SETTING SPOTIFY VOLUME 100 May 04 14:01:56 volumio volumio[866]: info: Sending Spotify command with payload to local API: /player/volume May 04 14:01:56 volumio go-librespot[1188]: time="2025-05-04T14:01:56-04:00" level=debug msg="update volume to 65535/65535" May 04 14:01:57 volumio go-librespot[1188]: time="2025-05-04T14:01:57-04:00" level=debug msg="put connect state because VOLUME_CHANGED" May 04 14:01:57 volumio go-librespot[1188]: time="2025-05-04T14:01:57-04:00" level=trace msg="emitting websocket event: volume" May 04 14:01:57 volumio volumio[866]: SPOTIFY: received: {"type":"volume","data":{"value":100,"max":100}} May 04 14:01:57 volumio volumio[866]: SPOTIFY: RECEIVED SPOTIFY VOLUME 100 May 04 14:02:08 volumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume May 04 14:02:08 volumio volumio[866]: error: MRS: impossible to set browserPlayback volume: device not found May 04 14:02:17 volumio volumio[866]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay May 04 14:02:17 volumio volumio[866]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom May 04 14:02:17 volumio volumio[866]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 04 14:02:17 volumio volumio[866]: TypeError: Cannot read property 'then' of undefined May 04 14:02:17 volumio volumio[866]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) May 04 14:02:17 volumio volumio[866]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2279:30) May 04 14:02:17 volumio volumio[866]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1456:26) May 04 14:02:17 volumio volumio[866]: at Socket.emit (events.js:315:20) May 04 14:02:17 volumio volumio[866]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 May 04 14:02:17 volumio volumio[866]: at processTicksAndRejections (internal/process/task_queues.js:75:11) May 04 14:02:17 volumio volumio[866]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 04 14:02:18 volumio sudo[2067]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-04 14:01 May 04 14:02:18 volumio sudo[2067]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 09:33:57 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="354f95cf0a6c2cbcd57b1aca3179c81c"