-- Logs begin at Thu 2019-11-07 09:42:43 UTC, end at Thu 2024-10-31 20:16:09 UTC. -- Oct 31 20:15:05 volumio volumio[824]: info: [{"prettyName":"Volumio Spotify Connect2","name":"volspotconnect2","category":"music_service","version":"0.9.7","icon":"fa-spotify","enabled":true,"active":true}] Oct 31 20:15:11 volumio volumio[824]: info: Downloading plugin at http://plugins.volumio.org/plugins/volumio/armhf/music_service/spop/spop.zip Oct 31 20:15:15 volumio volumio[824]: info: END DOWNLOAD: http://plugins.volumio.org/plugins/volumio/armhf/music_service/spop/spop.zip Oct 31 20:15:15 volumio volumio[824]: info: Folder /tmp/plugins removed Oct 31 20:15:17 volumio volumio[824]: info: Checking if plugin already exists Oct 31 20:15:17 volumio volumio[824]: info: Rename folder Oct 31 20:15:17 volumio volumio[824]: info: Folder /tmp/downloaded_plugin.zip removed Oct 31 20:15:17 volumio volumio[824]: info: Move to category Oct 31 20:15:19 volumio volumio[824]: info: Checking if install.sh is present Oct 31 20:15:19 volumio volumio[824]: info: Executing install.sh Oct 31 20:15:19 volumio sudo[18455]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/spop/install.sh Oct 31 20:15:19 volumio sudo[18455]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 20:15:19 volumio volumio[824]: info: Writing systemd unit Oct 31 20:15:19 volumio volumio[824]: info: Setting permissions Oct 31 20:15:19 volumio sudo[18455]: pam_unix(sudo:session): session closed for user root Oct 31 20:15:19 volumio volumio[824]: info: Writing startconnect unit Oct 31 20:15:19 volumio volumio[824]: Plugin install end detected on script Oct 31 20:15:19 volumio volumio[824]: info: Install script completed Oct 31 20:15:19 volumio volumio[824]: info: Adding reference to registry Oct 31 20:15:19 volumio volumio[824]: info: Done installing plugin. Oct 31 20:15:19 volumio volumio[824]: info: Folder /tmp/plugins removed Oct 31 20:15:19 volumio volumio[824]: info: Folder /tmp/downloaded_plugin.zip removed Oct 31 20:15:19 volumio volumio[824]: info: Folder /data/temp removed Oct 31 20:15:25 volumio volumio[824]: info: Downloading plugin at http://plugins.volumio.org/plugins/volumio/armhf/music_service/volspotconnect2/volspotconnect2.zip Oct 31 20:15:27 volumio volumio[824]: info: END DOWNLOAD: http://plugins.volumio.org/plugins/volumio/armhf/music_service/volspotconnect2/volspotconnect2.zip Oct 31 20:15:27 volumio volumio[824]: [SpotifyConnect] Relinquishing Volumio state, Spotify session: true Oct 31 20:15:27 volumio volumio[824]: UNSET VOLATILE Oct 31 20:15:27 volumio volumio[824]: [SpotifyConnect] unSetVolatile called Oct 31 20:15:27 volumio volumio[824]: [SpotifyConnect] Relinquishing Volumio state to another service, Spotify session: true Oct 31 20:15:27 volumio volumio[824]: [SpotifyConnect] Received stop Oct 31 20:15:27 volumio volumio[824]: [SpotifyConnect] FE => [ 4, [length]: 1 ] Oct 31 20:15:27 volumio volumio[824]: [SpotifyConnect] Killing vollibrespot daemon Oct 31 20:15:27 volumio volumio[824]: [SpotifyConnect] Closing metadata listener Oct 31 20:15:27 volumio volumio[824]: info: CoreStateMachine::resetVolumioState Oct 31 20:15:27 volumio volumio[824]: info: CoreStateMachine::getcurrentVolume Oct 31 20:15:27 volumio volumio[824]: info: CoreCommandRouter::volumioRetrievevolume Oct 31 20:15:27 volumio sudo[18485]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volspotconnect2.service Oct 31 20:15:27 volumio sudo[18485]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 20:15:27 volumio volumio[824]: info: CoreCommandRouter::volumioStop Oct 31 20:15:27 volumio volumio[824]: info: CoreStateMachine::stop Oct 31 20:15:27 volumio volumio[824]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 31 20:15:27 volumio volumio[824]: UNSET VOLATILE Oct 31 20:15:27 volumio systemd[1]: Stopping Volspotconnect2 Daemon... Oct 31 20:15:27 volumio systemd[1]: Stopped Volspotconnect2 Daemon. Oct 31 20:15:27 volumio sudo[18485]: pam_unix(sudo:session): session closed for user root Oct 31 20:15:27 volumio volumio[824]: info: VolumeController:: Volume=54 Mute =false Oct 31 20:15:27 volumio volumio[824]: info: CoreStateMachine::pushState Oct 31 20:15:27 volumio volumio[824]: info: CoreStateMachine::getState Oct 31 20:15:27 volumio volumio[824]: info: CorePlayQueue::getTrack 0 Oct 31 20:15:27 volumio volumio[824]: info: CoreCommandRouter::volumioPushState Oct 31 20:15:27 volumio volumio[824]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 31 20:15:27 volumio sudo[18499]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 31 20:15:27 volumio sudo[18499]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 20:15:27 volumio sudo[18499]: pam_unix(sudo:session): session closed for user root Oct 31 20:15:27 volumio volumio[824]: [SpotifyConnect] Not Found Oct 31 20:15:27 volumio volumio[824]: info: Rename folder Oct 31 20:15:27 volumio volumio[824]: info: Folder /tmp/downloaded_plugin.zip removed Oct 31 20:15:27 volumio volumio[824]: info: Move to category Oct 31 20:15:28 volumio volumio[824]: info: Checking if install.sh is present Oct 31 20:15:28 volumio volumio[824]: info: Executing install.sh Oct 31 20:15:28 volumio sudo[18517]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/volspotconnect2/install.sh Oct 31 20:15:28 volumio sudo[18517]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 20:15:28 volumio volumio[824]: info: Launching a bash shell Oct 31 20:15:28 volumio volumio[824]: info: Installing volspotconnect2 dependencies Oct 31 20:15:28 volumio volumio[824]: info: Cleaning old config flile Oct 31 20:15:28 volumio sudo[18526]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/rm /data/configuration/music_service/volspotconnect2/config.json Oct 31 20:15:28 volumio sudo[18526]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 20:15:28 volumio sudo[18526]: pam_unix(sudo:session): session closed for user root Oct 31 20:15:28 volumio volumio[824]: info: Detected cpu architecture as armv7l Oct 31 20:15:29 volumio volumio[824]: info: Latest version: v0.2.5 Requested version: v0.2.2 Oct 31 20:15:29 volumio volumio[824]: info: Supported device (arch = armv7l), downloading required packages for vollibrespot v0.2.2 Oct 31 20:15:29 volumio volumio[824]: info: Downloading file Oct 31 20:15:32 volumio volumio[824]: info: Extracting... Oct 31 20:15:32 volumio volumio[824]: info: -rw-r--r-- 1 root root 4289193 Oct 31 20:15 vollibrespot-armv7l.tar.xz Oct 31 20:15:33 volumio volumio[824]: info: vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07 Oct 31 20:15:33 volumio sudo[18562]: root : TTY=unknown ; PWD=/data/plugins/music_service/volspotconnect2 ; USER=root ; COMMAND=/bin/tar -xvf volspotconnect2.service.tar -C / Oct 31 20:15:33 volumio sudo[18562]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 20:15:33 volumio volumio[824]: info: etc/systemd/system/volspotconnect2.service Oct 31 20:15:33 volumio sudo[18562]: pam_unix(sudo:session): session closed for user root Oct 31 20:15:33 volumio sudo[18570]: root : TTY=unknown ; PWD=/data/plugins/music_service/volspotconnect2 ; USER=root ; COMMAND=/bin/chmod +x /data/plugins/music_service/volspotconnect2/onstart1.sh Oct 31 20:15:33 volumio sudo[18570]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 20:15:33 volumio sudo[18570]: pam_unix(sudo:session): session closed for user root Oct 31 20:15:33 volumio sudo[18517]: pam_unix(sudo:session): session closed for user root Oct 31 20:15:33 volumio volumio[824]: info: volspotconnect2 installed Oct 31 20:15:33 volumio volumio[824]: Plugin install end detected on script Oct 31 20:15:33 volumio volumio[824]: info: Install script completed Oct 31 20:15:33 volumio volumio[824]: info: Done installing plugin. Oct 31 20:15:33 volumio volumio[824]: info: Enabling plugin volspotconnect2 Oct 31 20:15:33 volumio volumio[824]: info: [{"prettyName":"Spotify","name":"spop","category":"music_service","version":"3.0.3","icon":"fa-spotify","enabled":false,"active":false},{"prettyName":"Volumio Spotify Connect2","name":"volspotconnect2","category":"music_service","version":"1.0.5","icon":"fa-spotify","enabled":true,"active":false}] Oct 31 20:15:33 volumio volumio[824]: info: Folder /tmp/plugins removed Oct 31 20:15:33 volumio volumio[824]: info: Folder /tmp/downloaded_plugin.zip removed Oct 31 20:15:33 volumio volumio[824]: info: Folder /data/temp removed Oct 31 20:15:59 volumio volumio[824]: info: Enabling plugin spop Oct 31 20:15:59 volumio volumio[824]: info: Loading plugin "spop"... Oct 31 20:16:01 volumio volumio[824]: info: PLUGIN START: spop Oct 31 20:16:01 volumio volumio[824]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 31 20:16:01 volumio volumio[824]: [SpotifyConnect] Creating VLS config file Oct 31 20:16:01 volumio volumio[824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 20:16:01 volumio volumio[824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 20:16:01 volumio volumio[824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 20:16:01 volumio volumio[824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 20:16:01 volumio volumio[824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 20:16:01 volumio volumio[824]: [SpotifyConnect] Starting metadata listener Oct 31 20:16:01 volumio sudo[18636]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hosts Oct 31 20:16:01 volumio sudo[18636]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 20:16:01 volumio sudo[18636]: pam_unix(sudo:session): session closed for user root Oct 31 20:16:01 volumio sudo[18642]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect.service Oct 31 20:16:01 volumio sudo[18642]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 20:16:01 volumio systemd[1]: Starting Volspotconnect2 Daemon... Oct 31 20:16:01 volumio systemd[1]: Started Volspotconnect2 Daemon. Oct 31 20:16:01 volumio volumio[18650]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-07-11 Oct 31 20:16:01 volumio volumio[18650]: Reading Config from "/tmp/volspotify.toml" Oct 31 20:16:01 volumio volumio[18650]: Malformed config key: missing field `Authentication` Oct 31 20:16:02 volumio sudo[18642]: pam_unix(sudo:session): session closed for user root Oct 31 20:16:02 volumio volumio[824]: [SpotifyConnect] Vollibrespot Daemon service started! Oct 31 20:16:02 volumio volumio[824]: SpotifyConnect: 673.514ms Oct 31 20:16:02 volumio volumio[824]: info: Done. Oct 31 20:16:02 volumio volumio[824]: info: Enabling plugin volspotconnect2 Oct 31 20:16:02 volumio volumio[824]: info: Loading plugin "volspotconnect2"... Oct 31 20:16:02 volumio volumio[824]: info: PLUGIN START: volspotconnect2 Oct 31 20:16:02 volumio sudo[18659]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect2.service Oct 31 20:16:02 volumio sudo[18659]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 31 20:16:02 volumio systemd[1]: Starting Volspotconnect2 Daemon... Oct 31 20:16:02 volumio systemd[1]: Started Volspotconnect2 Daemon. Oct 31 20:16:02 volumio sudo[18659]: pam_unix(sudo:session): session closed for user root Oct 31 20:16:02 volumio volumio[824]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 31 20:16:02 volumio volumio[18664]: vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07 Oct 31 20:16:02 volumio volumio[18664]: Unable to read config from "volspotify.toml", Using default config Oct 31 20:16:02 volumio volumio[18664]: [Vollibrespot] : Using Alsa backend with device: default Oct 31 20:16:02 volumio volumio[824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 20:16:02 volumio volumio[824]: info: CoreCommandRouter::volumioGetState Oct 31 20:16:02 volumio volumio[824]: info: CoreStateMachine::getState Oct 31 20:16:02 volumio volumio[824]: info: CorePlayQueue::getTrack 0 Oct 31 20:16:02 volumio volumio[824]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 31 20:16:02 volumio volumio[824]: info: Successfully fixed Spotify hosts Oct 31 20:16:02 volumio volumio[824]: [SpotifyConnect] Vollibrespot Daemon Started Oct 31 20:16:02 volumio volumio[824]: [SpotifyConnect] Starting metadata listener Oct 31 20:16:02 volumio volumio[824]: [SpotifyConnect] FE => [ 1, [length]: 1 ] Oct 31 20:16:02 volumio volumio[824]: [SpotifyConnect] Error: bind EADDRINUSE 0.0.0.0:5030 Oct 31 20:16:02 volumio volumio[824]: at Object._errnoException (util.js:1022:11) Oct 31 20:16:02 volumio volumio[824]: at _exceptionWithHostPort (util.js:1044:20) Oct 31 20:16:02 volumio volumio[824]: at _handle.lookup (dgram.js:266:18) Oct 31 20:16:02 volumio volumio[824]: at _combinedTickCallback (internal/process/next_tick.js:141:11) Oct 31 20:16:02 volumio volumio[824]: at process._tickCallback (internal/process/next_tick.js:180:9) Oct 31 20:16:02 volumio volumio[824]: [SpotifyConnect] Error [ERR_SOCKET_CANNOT_SEND]: Unable to send data Oct 31 20:16:02 volumio volumio[824]: at Socket.onListenError (dgram.js:362:22) Oct 31 20:16:02 volumio volumio[824]: at Object.onceWrapper (events.js:315:30) Oct 31 20:16:02 volumio volumio[824]: at emitOne (events.js:121:20) Oct 31 20:16:02 volumio volumio[824]: at Socket.emit (events.js:211:7) Oct 31 20:16:02 volumio volumio[824]: at _handle.lookup (dgram.js:267:14) Oct 31 20:16:02 volumio volumio[824]: at _combinedTickCallback (internal/process/next_tick.js:141:11) Oct 31 20:16:02 volumio volumio[824]: at process._tickCallback (internal/process/next_tick.js:180:9) Oct 31 20:16:02 volumio volumio[824]: info: Done. Oct 31 20:16:02 volumio volumio[18664]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" } Oct 31 20:16:04 volumio systemd[1]: volspotconnect.service holdoff time over, scheduling restart. Oct 31 20:16:04 volumio systemd[1]: Stopping Volspotconnect2 Daemon... Oct 31 20:16:04 volumio systemd[1]: Starting Volspotconnect2 Daemon... Oct 31 20:16:04 volumio systemd[1]: Started Volspotconnect2 Daemon. Oct 31 20:16:04 volumio volumio[18671]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-07-11 Oct 31 20:16:04 volumio volumio[18671]: Reading Config from "/tmp/volspotify.toml" Oct 31 20:16:04 volumio volumio[18671]: [Vollibrespot] : Using Alsa backend with device: plughw:1 Oct 31 20:16:04 volumio volumio[18671]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Uncategorized, message: "No such device" } Oct 31 20:16:06 volumio volumio[824]: info: Checking Spotify Web API Oct 31 20:16:07 volumio volumio[18671]: [Vollibrespot] : Connecting to AP "ap-gew4.spotify.com:443" Oct 31 20:16:07 volumio volumio[824]: info: CALLMETHOD: music_service spop saveVolspotconnectSettings [object Object] Oct 31 20:16:07 volumio volumio[824]: info: CoreCommandRouter::executeOnPlugin: spop , saveVolspotconnectSettings Oct 31 20:16:07 volumio volumio[824]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 31 20:16:07 volumio volumio[824]: TypeError: Cannot read property 'config' of undefined Oct 31 20:16:07 volumio volumio[824]: at ControllerSpotify.saveVolspotconnectSettings (/data/plugins/music_service/spop/index.js:2612:19) Oct 31 20:16:07 volumio volumio[824]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1076:29) Oct 31 20:16:07 volumio volumio[824]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:312:38) Oct 31 20:16:07 volumio volumio[824]: at emitTwo (events.js:126:13) Oct 31 20:16:07 volumio volumio[824]: at Socket.emit (events.js:214:7) Oct 31 20:16:07 volumio volumio[824]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Oct 31 20:16:07 volumio volumio[824]: at _combinedTickCallback (internal/process/next_tick.js:131:7) Oct 31 20:16:07 volumio volumio[824]: at process._tickCallback (internal/process/next_tick.js:180:9) Oct 31 20:16:07 volumio volumio[824]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 31 20:16:09 volumio sudo[18694]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-31 20:15 Oct 31 20:16:09 volumio sudo[18694]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 8 (jessie)" NAME="Raspbian GNU/Linux" VERSION_ID="8" VERSION="8 (jessie)" 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="6c3e4fa86d5413587e5bfd2f824b888a0ddfaa8b" VOLUMIO_FE_VERSION="" VOLUMIO_BE_VERSION="b78ecf1a48254ce8eadcc4803b4fff49030ca2e5" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Oct 18 15:58:42 CEST 2019" VOLUMIO_VERSION="2.657" VOLUMIO_HARDWARE="pi" VOLUMIO_HASH="ff0b4ec11fd1765611cb6e93a4e1e737"