-- Logs begin at Tue 2024-09-24 05:10:53 EDT, end at Sun 2024-12-01 12:33:11 EST. -- Dec 01 12:32:04 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:04 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:04 papouse volumio[1207]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 12:32:04 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:04 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:04 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:04 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:04 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:04 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:04 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:04 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:04 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:04 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:06 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:06 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:06 papouse volumio[1207]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 12:32:06 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:06 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:06 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:06 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:06 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:06 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:06 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:06 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:06 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:06 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:06 papouse shairport-sync[1410]: {"time":1733074314270,"response":"startAirplayPlayback Success"} % Total % Received % Xferd Average Speed Time Time Time Current Dec 01 12:32:06 papouse shairport-sync[1410]: Dload Upload Total Spent Left Speed Dec 01 12:32:06 papouse volumio[1207]: info: Dec 01 12:32:06 papouse volumio[1207]: ---------------------------- Client requests Stop Airplay Playback Dec 01 12:32:06 papouse volumio[1207]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , stopAirplayPlayback Dec 01 12:32:06 papouse volumio[1207]: info: Airplay playback stop Dec 01 12:32:06 papouse volumio[1207]: info: Airplay Playback Stopped, clearing state Dec 01 12:32:06 papouse volumio[1207]: info: CoreStateMachine::resetVolumioState Dec 01 12:32:06 papouse volumio[1207]: info: CoreStateMachine::getcurrentVolume Dec 01 12:32:06 papouse volumio[1207]: info: CoreCommandRouter::volumioRetrievevolume Dec 01 12:32:06 papouse shairport-sync[1410]: [158B blob data] Dec 01 12:32:06 papouse volumio[1207]: info: VolumeController:: Volume=100 Mute =false Dec 01 12:32:06 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:06 papouse volumio[1207]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 12:32:06 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:06 papouse volumio[1207]: info: CoreStateMachine::updateTrackBlock Dec 01 12:32:06 papouse volumio[1207]: info: CorePlayQueue::getTrackBlock Dec 01 12:32:06 papouse volumio[1207]: info: CoreCommandRouter::volumioRetrievevolume Dec 01 12:32:07 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:07 papouse volumio[1207]: info: VolumeController:: Volume=100 Mute =false Dec 01 12:32:07 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:07 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:07 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:08 papouse go-librespot[1997]: time="2024-12-01T12:32:08-05:00" level=error msg="did not receive last pong ack from accesspoint, 168240s passed" Dec 01 12:32:09 papouse volumio[1207]: info: Airplay started streaming, receiving metadatas Dec 01 12:32:09 papouse shairport-sync[1410]: {"time":1733074326879,"response":"stopAirplayPlayback Success"} % Total % Received % Xferd Average Speed Time Time Time Current Dec 01 12:32:09 papouse shairport-sync[1410]: Dload Upload Total Spent Left Speed Dec 01 12:32:09 papouse volumio[1207]: info: Dec 01 12:32:09 papouse volumio[1207]: ---------------------------- Client requests Start Airplay PlaybackRoutine Dec 01 12:32:09 papouse volumio[1207]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback Dec 01 12:32:09 papouse volumio[1207]: info: Airplay playback start Dec 01 12:32:09 papouse shairport-sync[1410]: [158B blob data] Dec 01 12:32:09 papouse go-librespot[1997]: time="2024-12-01T12:32:09-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1160" Dec 01 12:32:09 papouse go-librespot[1997]: time="2024-12-01T12:32:09-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 319" Dec 01 12:32:10 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:10 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:10 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:10 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:10 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:10 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:10 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:10 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:10 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:10 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:10 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:10 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:10 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:10 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:10 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:10 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:12 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:12 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:12 papouse volumio[1207]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 12:32:12 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:12 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:12 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:12 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:12 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:12 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:12 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:12 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:12 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:12 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:13 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:13 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:13 papouse volumio[1207]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 12:32:13 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:13 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:13 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:13 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:13 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:13 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:13 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:13 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:13 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:13 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:13 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:13 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:13 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:13 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:13 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:13 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:13 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:13 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:13 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:13 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:13 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:13 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:15 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:15 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:15 papouse volumio[1207]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 12:32:15 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:15 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:15 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:15 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:15 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:15 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:15 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:15 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:15 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:15 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:17 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:17 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:17 papouse volumio[1207]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 12:32:17 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:17 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:17 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:17 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:17 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:17 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:17 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:17 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:17 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:17 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:17 papouse go-librespot[1997]: time="2024-12-01T12:32:17-05:00" level=debug msg="fetched first chunk of 9, total size is 4509544 bytes" uri="spotify:track:3Wyxt6u636HVEl8xGP5h4O" Dec 01 12:32:17 papouse go-librespot[1997]: time="2024-12-01T12:32:17-05:00" level=trace msg="seek to 0ms (diff: 0ms, samples: 0, bytes: 0)" uri="spotify:track:3Wyxt6u636HVEl8xGP5h4O" Dec 01 12:32:44 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:44 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:44 papouse volumio[1207]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 12:32:44 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:44 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:44 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:44 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:44 papouse volumio[1207]: info: CoreCommandRouter::servicePushState Dec 01 12:32:44 papouse volumio[1207]: info: CoreStateMachine::pushState Dec 01 12:32:44 papouse volumio[1207]: info: CoreCommandRouter::volumioPushState Dec 01 12:32:44 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:44 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:44 papouse volumio[1207]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 12:32:48 papouse go-librespot[1997]: time="2024-12-01T12:32:48-05:00" level=debug msg="fetched chunk 1/8, size: 524288" uri="spotify:track:3Wyxt6u636HVEl8xGP5h4O" Dec 01 12:33:00 papouse go-librespot[1997]: time="2024-12-01T12:33:00-05:00" level=error msg="did not receive last pong from dealer, 40s passed" Dec 01 12:33:10 papouse volumio[1207]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 01 12:33:10 papouse volumio[1207]: Error: read ECONNRESET Dec 01 12:33:10 papouse volumio[1207]: at TLSWrap.onStreamRead (internal/stream_base_commons.js:209:20) { Dec 01 12:33:10 papouse volumio[1207]: errno: -104, Dec 01 12:33:10 papouse volumio[1207]: code: 'ECONNRESET', Dec 01 12:33:10 papouse volumio[1207]: syscall: 'read' Dec 01 12:33:10 papouse volumio[1207]: } Dec 01 12:33:10 papouse volumio[1207]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 01 12:33:11 papouse sudo[10263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-12-01 12:32 Dec 01 12:33:11 papouse sudo[10263]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"