-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2024-05-05 20:47:36 CEST. -- May 05 20:46:03 volumio-ess volumio[943]: [Vollibrespot] : Event: Play { track_id: SpotifyId { id: 47578315471144204409719577350926694317, audio_type: Track }, position_ms: 9078 } May 05 20:46:03 volumio-ess volumio[719]: [SpotifyConnect] play May 05 20:46:03 volumio-ess kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 May 05 20:46:03 volumio-ess volumio[943]: [Vollibrespot] : Event: SinkActive May 05 20:46:03 volumio-ess volumio[719]: [SpotifyConnect] Killing Me Softly May 05 20:46:03 volumio-ess volumio[719]: info: [1714934763335] ControllerSpotify::pushState May 05 20:46:03 volumio-ess volumio[719]: info: CoreCommandRouter::servicePushState May 05 20:46:03 volumio-ess volumio[719]: info: CoreStateMachine::pushState May 05 20:46:03 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 05 20:46:03 volumio-ess volumio[719]: info: CoreCommandRouter::volumioPushState May 05 20:46:03 volumio-ess volumio[719]: [SpotifyConnect] Sink acquired May 05 20:46:03 volumio-ess volumio[719]: info: Acquiring new spotify session May 05 20:46:03 volumio-ess volumio[719]: info: CoreCommandRouter::volumioStop May 05 20:46:03 volumio-ess volumio[719]: info: CoreStateMachine::stop May 05 20:46:03 volumio-ess volumio[719]: info: CoreStateMachine::serviceStop May 05 20:46:03 volumio-ess volumio[719]: info: CoreCommandRouter::serviceStop May 05 20:46:03 volumio-ess volumio[719]: [SpotifyConnect] Spotify Received stop May 05 20:46:03 volumio-ess volumio[943]: [Vollibrespot] : Pause May 05 20:46:03 volumio-ess volumio[943]: [Vollibrespot] : Event: Pause { track_id: SpotifyId { id: 47578315471144204409719577350926694317, audio_type: Track }, position_ms: 9634 } May 05 20:46:03 volumio-ess volumio[719]: [SpotifyConnect] Pause May 05 20:46:03 volumio-ess volumio[719]: [SpotifyConnect] pause May 05 20:46:03 volumio-ess volumio[719]: info: Checking Spotify Web API May 05 20:46:03 volumio-ess volumio[719]: [SpotifyConnect] Vollibrespot Active May 05 20:46:03 volumio-ess volumio[719]: info: CoreStateMachine::setConsumeUpdateService undefined May 05 20:46:03 volumio-ess volumio[719]: info: [1714934763842] ControllerSpotify::pushState May 05 20:46:03 volumio-ess volumio[719]: info: CoreCommandRouter::servicePushState May 05 20:46:03 volumio-ess volumio[719]: info: CoreStateMachine::pushState May 05 20:46:03 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 05 20:46:03 volumio-ess volumio[719]: info: CoreCommandRouter::volumioPushState May 05 20:46:03 volumio-ess volumio[719]: [SpotifyConnect] Killing Me Softly May 05 20:46:03 volumio-ess volumio[719]: info: [1714934763877] ControllerSpotify::pushState May 05 20:46:03 volumio-ess volumio[719]: info: CoreCommandRouter::servicePushState May 05 20:46:03 volumio-ess volumio[719]: info: CoreStateMachine::pushState May 05 20:46:03 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 05 20:46:03 volumio-ess volumio[719]: info: CoreCommandRouter::volumioPushState May 05 20:46:04 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetState May 05 20:46:04 volumio-ess volumio[943]: [Vollibrespot] : Event: SinkInactive May 05 20:46:04 volumio-ess volumio[943]: [Vollibrespot] : Event: PlaybackStopped { track_id: SpotifyId { id: 47578315471144204409719577350926694317, audio_type: Track } } May 05 20:46:04 volumio-ess volumio[719]: [SpotifyConnect] Sink released May 05 20:46:04 volumio-ess volumio[719]: info: [1714934764555] ControllerSpotify::pushState May 05 20:46:04 volumio-ess volumio[719]: info: CoreCommandRouter::servicePushState May 05 20:46:04 volumio-ess volumio[719]: info: CoreStateMachine::pushState May 05 20:46:04 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 05 20:46:04 volumio-ess volumio[719]: info: CoreCommandRouter::volumioPushState May 05 20:46:04 volumio-ess volumio[719]: [SpotifyConnect] Device palyback is inactive May 05 20:46:14 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetState May 05 20:46:14 volumio-ess volumio[719]: info: Listing playlists May 05 20:46:14 volumio-ess volumio[719]: info: Listing playlists May 05 20:46:15 volumio-ess volumio[719]: verbose: New Socket.io Connection to 192.168.1.178 from 192.168.1.232 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/605.1.15 (KHTML, like Gecko) Version/16.6 Safari/605.1.15 Total Clients: 5 May 05 20:46:15 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 05 20:46:15 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 05 20:46:15 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetVisibleSources May 05 20:46:15 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 05 20:46:15 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetState May 05 20:46:15 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetState May 05 20:46:15 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 05 20:46:15 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 05 20:46:15 volumio-ess volumio[719]: info: Received Get System Info May 05 20:46:15 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 05 20:46:15 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 05 20:46:15 volumio-ess volumio[719]: info: Discovery: Getting this device information May 05 20:46:15 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetState May 05 20:46:15 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 05 20:46:15 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetState May 05 20:46:15 volumio-ess volumio[719]: info: Listing playlists May 05 20:46:15 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 05 20:46:16 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetQueue May 05 20:46:16 volumio-ess volumio[719]: info: CoreStateMachine::getQueue May 05 20:46:16 volumio-ess volumio[719]: info: CorePlayQueue::getQueue May 05 20:46:22 volumio-ess sudo[1470]: pam_unix(sudo:session): session closed for user root May 05 20:46:22 volumio-ess volumio[719]: info: Cannot mount NAS at system boot, trial number 4 ,stopping May 05 20:46:23 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetState May 05 20:46:24 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetState May 05 20:46:26 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 05 20:46:26 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 05 20:46:34 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetState May 05 20:46:34 volumio-ess volumio[719]: info: Listing playlists May 05 20:46:34 volumio-ess volumio[719]: info: Listing playlists May 05 20:46:44 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetState May 05 20:46:54 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetState May 05 20:46:54 volumio-ess volumio[719]: info: Listing playlists May 05 20:46:54 volumio-ess volumio[719]: info: Listing playlists May 05 20:46:59 volumio-ess volumio[719]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/buster/armhf May 05 20:47:00 volumio-ess volumio[719]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/buster/armhf May 05 20:47:00 volumio-ess volumio[719]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify May 05 20:47:00 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 05 20:47:01 volumio-ess volumio[719]: [SpotifyConnect] Closing metadata listener May 05 20:47:01 volumio-ess sudo[1637]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volspotconnect.service May 05 20:47:01 volumio-ess sudo[1637]: pam_unix(sudo:session): session opened for user root by (uid=0) May 05 20:47:01 volumio-ess systemd[1]: Stopping Volspotconnect2 Daemon... May 05 20:47:01 volumio-ess systemd[1]: volspotconnect.service: Main process exited, code=killed, status=15/TERM May 05 20:47:01 volumio-ess systemd[1]: volspotconnect.service: Succeeded. May 05 20:47:01 volumio-ess systemd[1]: Stopped Volspotconnect2 Daemon. May 05 20:47:01 volumio-ess sudo[1637]: pam_unix(sudo:session): session closed for user root May 05 20:47:01 volumio-ess volumio[719]: [SpotifyConnect] Vollibrespot Daemon service stoped! May 05 20:47:01 volumio-ess volumio[719]: info: Check plugin dependencies May 05 20:47:01 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 05 20:47:01 volumio-ess volumio[719]: info: Rename folder May 05 20:47:01 volumio-ess volumio[719]: info: Folder /tmp/downloaded_plugin.zip removed May 05 20:47:01 volumio-ess volumio[719]: info: Move to category May 05 20:47:03 volumio-ess volumio[719]: info: Checking if install.sh is present May 05 20:47:03 volumio-ess volumio[719]: info: Executing install.sh May 05 20:47:03 volumio-ess sudo[1654]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/spop/install.sh May 05 20:47:03 volumio-ess sudo[1654]: pam_unix(sudo:session): session opened for user root by (uid=0) May 05 20:47:03 volumio-ess volumio[719]: info: Installing Go-librespot May 05 20:47:03 volumio-ess volumio[719]: info: Checking old vollibrespot installs May 05 20:47:03 volumio-ess systemd[1]: Reloading. May 05 20:47:03 volumio-ess systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. May 05 20:47:03 volumio-ess systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. May 05 20:47:03 volumio-ess systemd[1]: Reloading. May 05 20:47:03 volumio-ess systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. May 05 20:47:04 volumio-ess volumio[719]: info: Clearing old vollibrespot May 05 20:47:04 volumio-ess volumio[719]: info: vollibrespot cleared May 05 20:47:04 volumio-ess volumio[719]: info: Dowloading daemon May 05 20:47:04 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetState May 05 20:47:05 volumio-ess volumio[719]: info: Creating Start Script May 05 20:47:05 volumio-ess systemd[1]: Reloading. May 05 20:47:05 volumio-ess systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly. May 05 20:47:05 volumio-ess sudo[1654]: pam_unix(sudo:session): session closed for user root May 05 20:47:05 volumio-ess volumio[719]: Plugin install end detected on script May 05 20:47:05 volumio-ess volumio[719]: info: Install script completed May 05 20:47:05 volumio-ess volumio[719]: info: Done installing plugin. May 05 20:47:05 volumio-ess volumio[719]: info: Enabling plugin spop May 05 20:47:05 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 05 20:47:05 volumio-ess volumio[719]: info: [{"prettyName":"Spotify","name":"spop","category":"music_service","version":"4.0.4","icon":"fa-spotify","isManuallyInstalled":false,"enabled":true,"active":false}] May 05 20:47:05 volumio-ess volumio[719]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 05 20:47:05 volumio-ess volumio[719]: info: Folder /tmp/plugins removed May 05 20:47:05 volumio-ess volumio[719]: info: Folder /tmp/downloaded_plugin.zip removed May 05 20:47:05 volumio-ess volumio[719]: info: Folder /data/temp removed May 05 20:47:14 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetState May 05 20:47:14 volumio-ess volumio[719]: info: Listing playlists May 05 20:47:14 volumio-ess volumio[719]: info: Listing playlists May 05 20:47:17 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetState May 05 20:47:19 volumio-ess volumio[719]: info: CoreCommandRouter::volumioVolatilePlay May 05 20:47:19 volumio-ess volumio[719]: info: CoreStateMachine::volatilePlay May 05 20:47:19 volumio-ess volumio[719]: info: Spotify Play May 05 20:47:24 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetState May 05 20:47:34 volumio-ess volumio[719]: info: CoreCommandRouter::volumioGetState May 05 20:47:34 volumio-ess volumio[719]: info: Listing playlists May 05 20:47:34 volumio-ess volumio[719]: info: Listing playlists May 05 20:47:35 volumio-ess volumio[719]: info: Airplay started streaming, receiving metadatas May 05 20:47:35 volumio-ess volumio[719]: verbose: UNSET VOLATILE: Service: spop May 05 20:47:35 volumio-ess volumio[719]: [SpotifyConnect] unSetVolatile called May 05 20:47:35 volumio-ess volumio[719]: info: Spotify Unset Volatile called May 05 20:47:35 volumio-ess volumio[719]: [SpotifyConnect] Relinquishing Volumio State to another service May 05 20:47:35 volumio-ess volumio[719]: [SpotifyConnect] Spotify Received stop May 05 20:47:36 volumio-ess volumio[719]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 05 20:47:36 volumio-ess volumio[719]: Error [ERR_SOCKET_DGRAM_NOT_RUNNING]: Not running May 05 20:47:36 volumio-ess volumio[719]: at healthCheck (dgram.js:897:11) May 05 20:47:36 volumio-ess volumio[719]: at Socket.send (dgram.js:622:3) May 05 20:47:36 volumio-ess volumio[719]: at SpotConnEvents.sendmsg (/data/plugins/music_service/spop/SpotConnController.js:106:21) May 05 20:47:36 volumio-ess volumio[719]: at ControllerSpotify.stop (/data/plugins/music_service/spop/index.js:2717:19) May 05 20:47:36 volumio-ess volumio[719]: at ControllerSpotify.spotConnUnsetVolatile (/data/plugins/music_service/spop/index.js:2391:17) May 05 20:47:36 volumio-ess volumio[719]: at ControllerSpotify.unsetVol (/data/plugins/music_service/spop/index.js:68:21) May 05 20:47:36 volumio-ess volumio[719]: at CoreStateMachine.unSetVolatile (/volumio/app/statemachine.js:1541:27) May 05 20:47:36 volumio-ess volumio[719]: at AirPlayInterface.prepareAirplayPlayback (/volumio/app/plugins/music_service/airplay_emulation/index.js:541:39) May 05 20:47:36 volumio-ess volumio[719]: at ShairportSyncReaderUDP. (/volumio/app/plugins/music_service/airplay_emulation/index.js:257:12) May 05 20:47:36 volumio-ess volumio[719]: at ShairportSyncReaderUDP.emit (events.js:327:22) { May 05 20:47:36 volumio-ess volumio[719]: code: 'ERR_SOCKET_DGRAM_NOT_RUNNING' May 05 20:47:36 volumio-ess volumio[719]: } May 05 20:47:36 volumio-ess volumio[719]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 05 20:47:36 volumio-ess shairport-sync[966]: % Total % Received % Xferd Average Speed Time Time Time Current May 05 20:47:36 volumio-ess shairport-sync[966]: Dload Upload Total Spent Left Speed May 05 20:47:36 volumio-ess kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 May 05 20:47:36 volumio-ess kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 May 05 20:47:36 volumio-ess sudo[1732]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-05 20:46 May 05 20:47:36 volumio-ess sudo[1732]: 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="e7445fab547cd22e23d9bef72406cfb610bc1d7d" VOLUMIO_FE_VERSION="5d5e99f8f803b3ec5fc5e8ca13bb4023600f3eee" VOLUMIO_FE3_VERSION="a6ae210575eae1ff43f06ab71e1cd17576840623" VOLUMIO_BE_VERSION="a9e1e1dd6072ffb15c0fcb8938d9ea0d8900c0da" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 24 Apr 2024 02:10:14 PM CEST" VOLUMIO_VERSION="3.661" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="5bdefd4af4423fd17aacb83a8538bf1f"