-- Logs begin at Thu 2019-02-14 05:11:59 EST, end at Sat 2024-04-13 21:46:43 EDT. --
Apr 13 21:45:41 volumio ntpd[659]: 198.60.22.240 local addr 192.168.4.65 ->
Apr 13 21:45:52 volumio volumio[856]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7
Apr 13 21:45:52 volumio volumio[856]: info: Downloading plugin at http://127.0.0.1:3000/plugin-serve/volspotconnect2.zip
Apr 13 21:45:52 volumio volumio[856]: info: END DOWNLOAD: http://127.0.0.1:3000/plugin-serve/volspotconnect2.zip
Apr 13 21:45:52 volumio volumio[856]: info: Folder /tmp/plugins removed
Apr 13 21:45:52 volumio volumio[856]: info: Check plugin dependencies
Apr 13 21:45:52 volumio volumio[856]: info: Checking if plugin already exists
Apr 13 21:45:52 volumio volumio[856]: info: Rename folder
Apr 13 21:45:52 volumio volumio[856]: info: Folder /tmp/downloaded_plugin.zip removed
Apr 13 21:45:52 volumio volumio[856]: info: Move to category
Apr 13 21:45:55 volumio volumio[856]: info: Checking if install.sh is present
Apr 13 21:45:55 volumio volumio[856]: info: Executing install.sh
Apr 13 21:45:55 volumio sudo[5178]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/volspotconnect2/install.sh
Apr 13 21:45:55 volumio sudo[5178]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 13 21:45:55 volumio volumio[856]: info: Launching a bash shell
Apr 13 21:45:55 volumio volumio[856]: info: Installing volspotconnect2 dependencies
Apr 13 21:45:55 volumio volumio[856]: info: Detected cpu architecture as armv7l
Apr 13 21:45:55 volumio volumio[856]: info: Latest version: v0.2.5 Requested version: v0.2.2
Apr 13 21:45:55 volumio volumio[856]: info: Supported device (arch = armv7l), downloading required packages for vollibrespot v0.2.2
Apr 13 21:45:56 volumio volumio[856]: info: Downloading file
Apr 13 21:45:57 volumio volumio[856]: info: Extracting...
Apr 13 21:45:57 volumio volumio[856]: info: -rw-r--r-- 1 root root 4289193 Apr 13 21:45 vollibrespot-armv7l.tar.xz
Apr 13 21:45:57 volumio volumio[856]: info: vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07
Apr 13 21:45:57 volumio sudo[5205]: root : TTY=unknown ; PWD=/data/plugins/music_service/volspotconnect2 ; USER=root ; COMMAND=/bin/tar -xvf volspotconnect2.service.tar -C /
Apr 13 21:45:57 volumio sudo[5205]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 13 21:45:57 volumio volumio[856]: info: etc/systemd/system/volspotconnect2.service
Apr 13 21:45:57 volumio sudo[5205]: pam_unix(sudo:session): session closed for user root
Apr 13 21:45:57 volumio sudo[5207]: root : TTY=unknown ; PWD=/data/plugins/music_service/volspotconnect2 ; USER=root ; COMMAND=/bin/chmod +x /data/plugins/music_service/volspotconnect2/onstart1.sh
Apr 13 21:45:57 volumio sudo[5207]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 13 21:45:57 volumio sudo[5207]: pam_unix(sudo:session): session closed for user root
Apr 13 21:45:57 volumio sudo[5178]: pam_unix(sudo:session): session closed for user root
Apr 13 21:45:57 volumio volumio[856]: info: volspotconnect2 installed
Apr 13 21:45:57 volumio volumio[856]: Plugin install end detected on script
Apr 13 21:45:57 volumio volumio[856]: info: Install script completed
Apr 13 21:45:57 volumio volumio[856]: info: Adding reference to registry
Apr 13 21:45:57 volumio volumio[856]: info: Done installing plugin.
Apr 13 21:45:57 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 13 21:45:57 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Apr 13 21:45:57 volumio volumio[856]: info: Folder /tmp/plugins removed
Apr 13 21:45:57 volumio volumio[856]: info: Folder /tmp/downloaded_plugin.zip removed
Apr 13 21:45:57 volumio volumio[856]: info: Folder /data/temp removed
Apr 13 21:46:11 volumio ntpd[659]: 104.156.246.53 local addr 192.168.4.65 ->
Apr 13 21:46:13 volumio sudo[5431]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 13 21:46:13 volumio sudo[5431]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 13 21:46:13 volumio sudo[5431]: pam_unix(sudo:session): session closed for user root
Apr 13 21:46:13 volumio sudo[5433]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 13 21:46:13 volumio sudo[5433]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 13 21:46:13 volumio sudo[5433]: pam_unix(sudo:session): session closed for user root
Apr 13 21:46:14 volumio volumio[856]: verbose: New Socket.io Connection to 192.168.4.65 from 192.168.4.35 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:124.0) Gecko/20100101 Firefox/124.0 Total Clients: 7
Apr 13 21:46:15 volumio sudo[5437]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 13 21:46:15 volumio sudo[5437]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 13 21:46:15 volumio sudo[5437]: pam_unix(sudo:session): session closed for user root
Apr 13 21:46:15 volumio sudo[5440]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 13 21:46:15 volumio sudo[5440]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 13 21:46:15 volumio sudo[5440]: pam_unix(sudo:session): session closed for user root
Apr 13 21:46:15 volumio volumio[856]: verbose: New Socket.io Connection to 192.168.4.65 from 192.168.4.35 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.15; rv:124.0) Gecko/20100101 Firefox/124.0 Total Clients: 7
Apr 13 21:46:15 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted
Apr 13 21:46:15 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Apr 13 21:46:15 volumio volumio[856]: info: CoreCommandRouter::volumioGetVisibleSources
Apr 13 21:46:15 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 13 21:46:15 volumio volumio[856]: info: CoreCommandRouter::volumioGetState
Apr 13 21:46:15 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Apr 13 21:46:15 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Apr 13 21:46:15 volumio volumio[856]: info: Received Get System Info
Apr 13 21:46:15 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 13 21:46:15 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 13 21:46:15 volumio volumio[856]: info: Discovery: Getting this device information
Apr 13 21:46:15 volumio volumio[856]: info: CoreCommandRouter::volumioGetState
Apr 13 21:46:15 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 13 21:46:15 volumio volumio[856]: info: CoreCommandRouter::volumioGetState
Apr 13 21:46:16 volumio volumio[856]: info: Listing playlists
Apr 13 21:46:16 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Apr 13 21:46:16 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Apr 13 21:46:16 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache
Apr 13 21:46:16 volumio volumio[856]: info: CoreCommandRouter::volumioGetState
Apr 13 21:46:16 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 13 21:46:16 volumio volumio[856]: info: Received Get System Info
Apr 13 21:46:16 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 13 21:46:16 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 13 21:46:16 volumio volumio[856]: info: Discovery: Getting this device information
Apr 13 21:46:16 volumio volumio[856]: info: CoreCommandRouter::volumioGetState
Apr 13 21:46:16 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 13 21:46:16 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Apr 13 21:46:17 volumio volumio[856]: info: CoreCommandRouter::Close All Modals sent
Apr 13 21:46:17 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: appearance , setTOSAccepted
Apr 13 21:46:20 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 13 21:46:20 volumio volumio[856]: info: Received Get System Info
Apr 13 21:46:20 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 13 21:46:20 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 13 21:46:20 volumio volumio[856]: info: Discovery: Getting this device information
Apr 13 21:46:20 volumio volumio[856]: info: CoreCommandRouter::volumioGetState
Apr 13 21:46:20 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 13 21:46:20 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Apr 13 21:46:20 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Apr 13 21:46:23 volumio volumio[856]: info: Enabling plugin volspotconnect2
Apr 13 21:46:23 volumio volumio[856]: info: Loading plugin "volspotconnect2"...
Apr 13 21:46:23 volumio volumio[856]: info: PLUGIN START: volspotconnect2
Apr 13 21:46:23 volumio volumio[856]: [SpotifyConnect] Creating VLS config file
Apr 13 21:46:23 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 21:46:23 volumio volumio[856]: [SpotifyConnect] /tmp/volume: 75
Apr 13 21:46:23 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 21:46:23 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 21:46:23 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 21:46:23 volumio volumio[856]: [SpotifyConnect] Volumio alsa_controller configuration:
Apr 13 21:46:23 volumio volumio[856]: outdev:volumio
Apr 13 21:46:23 volumio volumio[856]: outputdevicemixer:2
Apr 13 21:46:23 volumio volumio[856]: volcurve:logarithmic
Apr 13 21:46:23 volumio volumio[856]: mixtype:Hardware
Apr 13 21:46:23 volumio volumio[856]: mixname:Digital
Apr 13 21:46:23 volumio volumio[856]:
Apr 13 21:46:23 volumio volumio[856]: [SpotifyConnect] MODULAR_ALSA_PIPELINE: true
Apr 13 21:46:23 volumio volumio[856]: [SpotifyConnect]
Apr 13 21:46:23 volumio volumio[856]: outdev:volumio
Apr 13 21:46:23 volumio volumio[856]: mixer:alsa
Apr 13 21:46:23 volumio volumio[856]: mixname:Digital
Apr 13 21:46:23 volumio volumio[856]: mixdev:hw:2
Apr 13 21:46:23 volumio volumio[856]: mixidx:0
Apr 13 21:46:23 volumio volumio[856]:
Apr 13 21:46:23 volumio volumio[856]: [SpotifyConnect] Starting metadata listener
Apr 13 21:46:23 volumio sudo[5447]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect2.service
Apr 13 21:46:23 volumio sudo[5447]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 13 21:46:23 volumio systemd[1]: Started Volspotconnect2 Daemon.
Apr 13 21:46:23 volumio sudo[5447]: pam_unix(sudo:session): session closed for user root
Apr 13 21:46:23 volumio volumio[5449]: vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07
Apr 13 21:46:23 volumio volumio[5449]: Reading Config from "volspotify.toml"
Apr 13 21:46:23 volumio volumio[5449]: [Vollibrespot] : Using Alsa backend with device: volumio
Apr 13 21:46:23 volumio volumio[856]: [SpotifyConnect] Vollibrespot Daemon service started!
Apr 13 21:46:23 volumio volumio[856]: [Metrics] SpotifyConnect: 0s 122.66ms
Apr 13 21:46:23 volumio volumio[856]: info: Done.
Apr 13 21:46:23 volumio volumio[5449]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" }
Apr 13 21:46:24 volumio go-librespot[1025]: time="2024-04-13T21:46:24-04:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF"
Apr 13 21:46:24 volumio volumio[856]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesSpotify
Apr 13 21:46:24 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 13 21:46:24 volumio volumio[856]: info: Disabling plugin spop
Apr 13 21:46:24 volumio volumio[856]: info: Done.
Apr 13 21:46:24 volumio sudo[5452]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop go-librespot-daemon.service
Apr 13 21:46:24 volumio sudo[5452]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 13 21:46:24 volumio volumio[856]: info: Connection to go-librespot Websocket closed
Apr 13 21:46:24 volumio systemd[1]: Stopping go-librespot Daemon...
Apr 13 21:46:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM
Apr 13 21:46:24 volumio systemd[1]: go-librespot-daemon.service: Succeeded.
Apr 13 21:46:24 volumio systemd[1]: Stopped go-librespot Daemon.
Apr 13 21:46:24 volumio sudo[5452]: pam_unix(sudo:session): session closed for user root
Apr 13 21:46:25 volumio volumio[856]: info: CoreCommandRouter::getUIConfigOnPlugin
Apr 13 21:46:25 volumio volumio[856]: [SpotifyConnect] config : toggling initvol/volume_ctrl
Apr 13 21:46:33 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Apr 13 21:46:33 volumio volumio[856]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined
Apr 13 21:46:33 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates
Apr 13 21:46:33 volumio volumio[856]: info: Received Get System Version
Apr 13 21:46:33 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 13 21:46:33 volumio volumio[856]: info: Received Get System Info
Apr 13 21:46:33 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Apr 13 21:46:33 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Apr 13 21:46:33 volumio volumio[856]: info: Discovery: Getting this device information
Apr 13 21:46:33 volumio volumio[856]: info: CoreCommandRouter::volumioGetState
Apr 13 21:46:33 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 13 21:46:35 volumio volumio[856]: info: CALLMETHOD: music_service volspotconnect2 saveVolspotconnectAccount [object Object]
Apr 13 21:46:35 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volspotconnect2 , saveVolspotconnectAccount
Apr 13 21:46:35 volumio volumio[856]: [SpotifyConnect] Creating VLS config file
Apr 13 21:46:35 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 21:46:35 volumio volumio[856]: [SpotifyConnect] /tmp/volume: 75
Apr 13 21:46:35 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 21:46:35 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 21:46:35 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 13 21:46:35 volumio volumio[856]: [SpotifyConnect] Volumio alsa_controller configuration:
Apr 13 21:46:35 volumio volumio[856]: outdev:volumio
Apr 13 21:46:35 volumio volumio[856]: outputdevicemixer:2
Apr 13 21:46:35 volumio volumio[856]: volcurve:logarithmic
Apr 13 21:46:35 volumio volumio[856]: mixtype:Hardware
Apr 13 21:46:35 volumio volumio[856]: mixname:Digital
Apr 13 21:46:35 volumio volumio[856]:
Apr 13 21:46:35 volumio volumio[856]: [SpotifyConnect] MODULAR_ALSA_PIPELINE: true
Apr 13 21:46:35 volumio volumio[856]: [SpotifyConnect] Unimplemented debug mode!!
Apr 13 21:46:35 volumio volumio[856]: [SpotifyConnect]
Apr 13 21:46:35 volumio volumio[856]: outdev:volumio
Apr 13 21:46:35 volumio volumio[856]: mixer:alsa
Apr 13 21:46:35 volumio volumio[856]: mixname:Digital
Apr 13 21:46:35 volumio volumio[856]: mixdev:hw:2
Apr 13 21:46:35 volumio volumio[856]: mixidx:0
Apr 13 21:46:35 volumio volumio[856]:
Apr 13 21:46:35 volumio volumio[856]: [SpotifyConnect] Restarting Vollibrespot Daemon
Apr 13 21:46:35 volumio sudo[5493]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect2.service
Apr 13 21:46:35 volumio sudo[5493]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 13 21:46:35 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Apr 13 21:46:35 volumio systemd[1]: volspotconnect2.service: Main process exited, code=killed, status=15/TERM
Apr 13 21:46:35 volumio systemd[1]: volspotconnect2.service: Succeeded.
Apr 13 21:46:35 volumio systemd[1]: Stopped Volspotconnect2 Daemon.
Apr 13 21:46:35 volumio systemd[1]: Started Volspotconnect2 Daemon.
Apr 13 21:46:35 volumio sudo[5493]: pam_unix(sudo:session): session closed for user root
Apr 13 21:46:35 volumio volumio[856]: [SpotifyConnect] Vollibrespot Daemon service restarted!
Apr 13 21:46:35 volumio volumio[5495]: vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07
Apr 13 21:46:35 volumio volumio[5495]: Reading Config from "volspotify.toml"
Apr 13 21:46:35 volumio volumio[5495]: [Vollibrespot] : Using Alsa backend with device: volumio
Apr 13 21:46:35 volumio volumio[5495]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" }
Apr 13 21:46:42 volumio volumio[5495]: [Vollibrespot] : Connecting to AP "ap-gue1.spotify.com:443"
Apr 13 21:46:43 volumio volumio[5495]: [Vollibrespot] : Authenticated as "patrickdinh12" !
Apr 13 21:46:43 volumio volumio[5495]: [Vollibrespot] : Setting up new mixer: card:hw:2 mixer:Digital index:0
Apr 13 21:46:43 volumio volumio[5495]: [Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(-9999999)[dB]) -- max: 207 (MilliBel(0)[dB]) HW: true
Apr 13 21:46:43 volumio volumio[5495]: [Vollibrespot] : Using alsa sink
Apr 13 21:46:43 volumio volumio[5495]: [Vollibrespot] : Country: "US"
Apr 13 21:46:43 volumio volumio[5495]: [Vollibrespot] : Metadata pipe established
Apr 13 21:46:43 volumio volumio[5495]: [Vollibrespot] : Event: Volume { volume_to_mixer: 49151 }
Apr 13 21:46:43 volumio volumio[856]: [SpotifyConnect] 74.99961852445259
Apr 13 21:46:43 volumio volumio[856]: [SpotifyConnect] Volume: Spotify:74.99961852445259 Volumio: 75
Apr 13 21:46:43 volumio volumio[856]: info: CoreStateMachine::pushState
Apr 13 21:46:43 volumio volumio[856]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 13 21:46:43 volumio volumio[856]: info: CoreCommandRouter::volumioPushState
Apr 13 21:46:43 volumio volumio[5495]: [Vollibrespot] : Fetching autoplay context uri
Apr 13 21:46:43 volumio volumio[5495]: [Vollibrespot] : Event: SessionActive { became_active_at: 1713059203434 }
Apr 13 21:46:43 volumio volumio[5495]: [Vollibrespot] : SessionActive!
Apr 13 21:46:43 volumio volumio[5495]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 69398495987789194020276452371324869261, audio_type: Track } }
Apr 13 21:46:43 volumio volumio[5495]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 69398495987789194020276452371324869261, audio_type: Track } }
Apr 13 21:46:43 volumio volumio[856]: [SpotifyConnect] A connect session has begun
Apr 13 21:46:43 volumio volumio[856]: [SpotifyConnect] Device palyback is active!
Apr 13 21:46:43 volumio volumio[856]: info: CoreCommandRouter::volumioGetState
Apr 13 21:46:43 volumio volumio[856]: [SpotifyConnect] Currently active: spop
Apr 13 21:46:43 volumio volumio[856]: [SpotifyConnect] Stopping currently active service
Apr 13 21:46:43 volumio volumio[856]: info: CoreCommandRouter::volumioStop
Apr 13 21:46:43 volumio volumio[856]: info: CoreStateMachine::stop
Apr 13 21:46:43 volumio volumio[856]: info: CoreStateMachine::serviceStop
Apr 13 21:46:43 volumio volumio[856]: info: CoreCommandRouter::serviceStop
Apr 13 21:46:43 volumio volumio[856]: error: WARNING: No stop method for service spop
Apr 13 21:46:43 volumio volumio[856]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 13 21:46:43 volumio volumio[856]: TypeError: Cannot read property 'then' of undefined
Apr 13 21:46:43 volumio volumio[856]: at SpotConnEvents. (/data/plugins/music_service/volspotconnect2/index.js:145:23)
Apr 13 21:46:43 volumio volumio[856]: at SpotConnEvents.emit (events.js:315:20)
Apr 13 21:46:43 volumio volumio[856]: at SpotConnEvents.parseData (/data/plugins/music_service/volspotconnect2/SpotConnController.js:73:16)
Apr 13 21:46:43 volumio volumio[856]: at Socket. (/data/plugins/music_service/volspotconnect2/SpotConnController.js:15:12)
Apr 13 21:46:43 volumio volumio[856]: at Socket.emit (events.js:315:20)
Apr 13 21:46:43 volumio volumio[856]: at UDP.onMessage [as onmessage] (dgram.js:919:8)
Apr 13 21:46:43 volumio volumio[856]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 13 21:46:43 volumio volumio[5495]: [Vollibrespot] : error 403 for uri hm://keymaster/token/authenticated?client_id=4ced2e7c73484127be5d36015752eb43&scope=streaming,user-read-playback-state,user-modify-playback-state,user-read-currently-playing,user-read-private
Apr 13 21:46:43 volumio volumio[5495]: [Vollibrespot] : Error: MercuryError
Apr 13 21:46:43 volumio volumio[5495]: thread 'main' panicked at 'cannot poll Map twice', /build/cache/registry/src/github.com-1ecc6299db9ec823/futures-0.1.29/src/future/map.rs:35:29
Apr 13 21:46:43 volumio volumio[5495]: stack backtrace:
Apr 13 21:46:43 volumio volumio[5495]: 0: 0x9dc33c - backtrace::backtrace::libunwind::trace::hae21a072c81e5842
Apr 13 21:46:43 volumio volumio[5495]: at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/libunwind.rs:86
Apr 13 21:46:43 volumio volumio[5495]: 1: 0x9dc33c - backtrace::backtrace::trace_unsynchronized::h0f9b260087e46e47
Apr 13 21:46:43 volumio volumio[5495]: at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/mod.rs:66
Apr 13 21:46:43 volumio volumio[5495]: 2: 0x9dc33c - std::sys_common::backtrace::_print_fmt::hbf1a59173a7860c3
Apr 13 21:46:43 volumio volumio[5495]: at src/libstd/sys_common/backtrace.rs:78
Apr 13 21:46:43 volumio volumio[5495]: 3: 0x9dc33c - ::fmt::he1a5d6f378e506c4
Apr 13 21:46:43 volumio volumio[5495]: at src/libstd/sys_common/backtrace.rs:59
Apr 13 21:46:43 volumio volumio[5495]: 4: 0x9fcd5c - core::fmt::write::hb37ae5a5e0b70623
Apr 13 21:46:43 volumio volumio[5495]: at src/libcore/fmt/mod.rs:1076
Apr 13 21:46:43 volumio volumio[5495]: 5: 0x9d5c64 - std::io::Write::write_fmt::ha24bb3f5a858327b
Apr 13 21:46:43 volumio volumio[5495]: at src/libstd/io/mod.rs:1537
Apr 13 21:46:43 volumio volumio[5495]: 6: 0x9de974 - std::sys_common::backtrace::_print::h47b03aa1342833e3
Apr 13 21:46:43 volumio volumio[5495]: at src/libstd/sys_common/backtrace.rs:62
Apr 13 21:46:43 volumio volumio[5495]: 7: 0x9de974 - std::sys_common::backtrace::print::h2217cbc390250439
Apr 13 21:46:43 volumio volumio[5495]: at src/libstd/sys_common/backtrace.rs:49
Apr 13 21:46:43 volumio volumio[5495]: 8: 0x9de974 - std::panicking::default_hook::{{closure}}::h179f5229ea1c8e30
Apr 13 21:46:43 volumio volumio[5495]: at src/libstd/panicking.rs:198
Apr 13 21:46:43 volumio volumio[5495]: 9: 0x9de640 - std::panicking::default_hook::h46ab82039cbc65eb
Apr 13 21:46:43 volumio volumio[5495]: at src/libstd/panicking.rs:217
Apr 13 21:46:43 volumio volumio[5495]: 10: 0x9df054 - std::panicking::rust_panic_with_hook::h7326c48419bc7c33
Apr 13 21:46:43 volumio volumio[5495]: at src/libstd/panicking.rs:526
Apr 13 21:46:43 volumio volumio[5495]: 11: 0x9dec54 - rust_begin_unwind
Apr 13 21:46:43 volumio volumio[5495]: at src/libstd/panicking.rs:437
Apr 13 21:46:43 volumio volumio[5495]: 12: 0x9fa594 - core::panicking::panic_fmt::ha292e19d5ae716ed
Apr 13 21:46:43 volumio volumio[5495]: at src/libcore/panicking.rs:85
Apr 13 21:46:43 volumio volumio[5495]: 13: 0x9fa370 - core::option::expect_failed::he9e39f8f5ba60ecb
Apr 13 21:46:43 volumio volumio[5495]: at src/libcore/option.rs:1261
Apr 13 21:46:43 volumio volumio[5495]: 14: 0x6d0bf8 - as futures::future::Future>::poll::h3d56b212ca27d9e4
Apr 13 21:46:43 volumio volumio[5495]: 15: 0x5863a4 - ::poll::ha2e91a6b75c719f3
Apr 13 21:46:43 volumio volumio[5495]: 16: 0x4fcca4 - ::poll::hc5e7d2d1b7dbef13
Apr 13 21:46:43 volumio volumio[5495]: 17: 0x4c4844 - futures::task_impl::std::set::h8f081cf0436110c9
Apr 13 21:46:43 volumio volumio[5495]: 18: 0x4d841c - std::thread::local::LocalKey::with::h711a13323aafc45a
Apr 13 21:46:43 volumio volumio[5495]: 19: 0x4b4a50 - tokio_current_thread::Entered::block_on::h339073902a399eb7
Apr 13 21:46:43 volumio volumio[5495]: 20: 0x4d8e00 - std::thread::local::LocalKey::with::hff64c13ccfec5327
Apr 13 21:46:43 volumio volumio[5495]: 21: 0x4e520c - tokio_reactor::with_default::h7ef12e65cb103d2f
Apr 13 21:46:43 volumio volumio[5495]: 22: 0x4b89f8 - tokio::runtime::current_thread::runtime::Runtime::block_on::h043f136d6b8cf48f
Apr 13 21:46:43 volumio volumio[5495]: 23: 0x4fe2c8 - vollibrespot::main::h02a0d49d4cc5eaa6
Apr 13 21:46:43 volumio volumio[5495]: 24: 0x4e5f18 - std::rt::lang_start::{{closure}}::h279cd2b7929fdba7
Apr 13 21:46:43 volumio volumio[5495]: 25: 0x9df404 - std::rt::lang_start_internal::{{closure}}::he93bfc404849b78a
Apr 13 21:46:43 volumio volumio[5495]: at src/libstd/rt.rs:52
Apr 13 21:46:43 volumio volumio[5495]: 26: 0x9df404 - std::panicking::try::do_call::h6e9e98f4078affb0
Apr 13 21:46:43 volumio volumio[5495]: at src/libstd/panicking.rs:348
Apr 13 21:46:43 volumio volumio[5495]: 27: 0x9df404 - std::panicking::try::h2e68d4f7f799a6df
Apr 13 21:46:43 volumio volumio[5495]: at src/libstd/panicking.rs:325
Apr 13 21:46:43 volumio volumio[5495]: 28: 0x9df404 - std::panic::catch_unwind::h8880a4c07cc66391
Apr 13 21:46:43 volumio volumio[5495]: at src/libstd/panic.rs:394
Apr 13 21:46:43 volumio volumio[5495]: 29: 0x9df404 - std::rt::lang_start_internal::hf4ae2140248bf16b
Apr 13 21:46:43 volumio volumio[5495]: at src/libstd/rt.rs:51
Apr 13 21:46:43 volumio volumio[5495]: 30: 0x4fed84 - main
Apr 13 21:46:43 volumio volumio[5495]: 31: 0xb6c9e768 - __libc_start_main
Apr 13 21:46:43 volumio volumio[5495]: [Vollibrespot] : EventSender disconnected
Apr 13 21:46:43 volumio systemd[1]: volspotconnect2.service: Main process exited, code=exited, status=101/n/a
Apr 13 21:46:43 volumio systemd[1]: volspotconnect2.service: Failed with result 'exit-code'.
Apr 13 21:46:43 volumio sudo[5515]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-13 21:45
Apr 13 21:46:43 volumio sudo[5515]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d"
VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71"
VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1"
VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET"
VOLUMIO_VERSION="3.631"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"