-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Wed 2025-04-30 23:44:49 CEST. -- Apr 30 23:43:00 el-toro-audioteka volumio[902]: verbose: New Socket.io Connection to 192.168.1.68 from 192.168.1.47 UA: Mozilla/5.0 (Linux; Android 16; Pixel 8 Pro Build/BP22.250325.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.111 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetVisibleSources Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: Received Get System Info Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: Discovery: Getting this device information Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: Listing playlists Apr 30 23:43:00 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 30 23:43:05 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 30 23:43:05 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 30 23:43:27 el-toro-audioteka volumio[902]: info: Enabling plugin spop Apr 30 23:43:27 el-toro-audioteka volumio[902]: info: Loading plugin "spop"... Apr 30 23:43:28 el-toro-audioteka volumio[902]: info: PLUGIN START: spop Apr 30 23:43:28 el-toro-audioteka volumio[902]: info: Creating Spotify config file Apr 30 23:43:28 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 30 23:43:28 el-toro-audioteka volumio[902]: info: Done. Apr 30 23:43:28 el-toro-audioteka volumio[902]: info: Spotify config file written Apr 30 23:43:28 el-toro-audioteka volumio[902]: info: No need to fix Spotify hosts Apr 30 23:43:28 el-toro-audioteka sudo[3951]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 30 23:43:28 el-toro-audioteka sudo[3951]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 23:43:28 el-toro-audioteka systemd[1]: Started go-librespot Daemon. Apr 30 23:43:28 el-toro-audioteka go-librespot[3953]: go-librespot daemon starting... Apr 30 23:43:28 el-toro-audioteka sudo[3951]: pam_unix(sudo:session): session closed for user root Apr 30 23:43:28 el-toro-audioteka go-librespot[3953]: time="2025-04-30T23:43:28+02:00" level=info msg="running go-librespot 0.2.0" Apr 30 23:43:28 el-toro-audioteka go-librespot[3953]: time="2025-04-30T23:43:28+02:00" level=debug msg="no app state found" Apr 30 23:43:28 el-toro-audioteka go-librespot[3953]: time="2025-04-30T23:43:28+02:00" level=debug msg="stored credentials not found" Apr 30 23:43:28 el-toro-audioteka go-librespot[3953]: time="2025-04-30T23:43:28+02:00" level=info msg="generated new device id: 2156a234a4a70d417cc57aedbfffd06268bff606" Apr 30 23:43:28 el-toro-audioteka go-librespot[3953]: time="2025-04-30T23:43:28+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 30 23:43:28 el-toro-audioteka volumio[902]: info: Enabling plugin now_playing Apr 30 23:43:28 el-toro-audioteka volumio[902]: info: Loading plugin "now_playing"... Apr 30 23:43:28 el-toro-audioteka volumio[902]: error: !!!! WARNING !!!! Apr 30 23:43:28 el-toro-audioteka volumio[902]: error: The plugin user_interface/now_playing failed to load, setting it to stopped. Error: Error: Cannot find module 'geo-tz' Apr 30 23:43:28 el-toro-audioteka volumio[902]: Require stack: Apr 30 23:43:28 el-toro-audioteka volumio[902]: - /data/plugins/user_interface/now_playing/dist/index.js Apr 30 23:43:28 el-toro-audioteka volumio[902]: - /volumio/app/pluginmanager.js Apr 30 23:43:28 el-toro-audioteka volumio[902]: - /volumio/app/index.js Apr 30 23:43:28 el-toro-audioteka volumio[902]: - /volumio/index.js Apr 30 23:43:28 el-toro-audioteka volumio[902]: error: Stack trace: Error: Cannot find module 'geo-tz' Apr 30 23:43:28 el-toro-audioteka volumio[902]: Require stack: Apr 30 23:43:28 el-toro-audioteka volumio[902]: - /data/plugins/user_interface/now_playing/dist/index.js Apr 30 23:43:28 el-toro-audioteka volumio[902]: - /volumio/app/pluginmanager.js Apr 30 23:43:28 el-toro-audioteka volumio[902]: - /volumio/app/index.js Apr 30 23:43:28 el-toro-audioteka volumio[902]: - /volumio/index.js Apr 30 23:43:28 el-toro-audioteka volumio[902]: at Function.Module._resolveFilename (internal/modules/cjs/loader.js:880:15) Apr 30 23:43:28 el-toro-audioteka volumio[902]: at Function.Module._load (internal/modules/cjs/loader.js:725:27) Apr 30 23:43:28 el-toro-audioteka volumio[902]: at Module.require (internal/modules/cjs/loader.js:952:19) Apr 30 23:43:28 el-toro-audioteka volumio[902]: at require (internal/modules/cjs/helpers.js:88:18) Apr 30 23:43:28 el-toro-audioteka volumio[902]: at Object. (/data/plugins/user_interface/now_playing/dist/index.js:46:34) Apr 30 23:43:28 el-toro-audioteka volumio[902]: at Module._compile (internal/modules/cjs/loader.js:1063:30) Apr 30 23:43:28 el-toro-audioteka volumio[902]: at Object.Module._extensions..js (internal/modules/cjs/loader.js:1092:10) Apr 30 23:43:28 el-toro-audioteka volumio[902]: at Module.load (internal/modules/cjs/loader.js:928:32) Apr 30 23:43:28 el-toro-audioteka volumio[902]: at Function.Module._load (internal/modules/cjs/loader.js:769:14) Apr 30 23:43:28 el-toro-audioteka volumio[902]: at Module.require (internal/modules/cjs/loader.js:952:19) Apr 30 23:43:28 el-toro-audioteka volumio[902]: at require (internal/modules/cjs/helpers.js:88:18) Apr 30 23:43:28 el-toro-audioteka volumio[902]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:235:29) Apr 30 23:43:28 el-toro-audioteka volumio[902]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) Apr 30 23:43:28 el-toro-audioteka volumio[902]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Apr 30 23:43:28 el-toro-audioteka volumio[902]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Apr 30 23:43:28 el-toro-audioteka volumio[902]: error: !!!! WARNING !!!! Apr 30 23:43:28 el-toro-audioteka volumio[902]: info: Done. Apr 30 23:43:28 el-toro-audioteka go-librespot[3953]: time="2025-04-30T23:43:28+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 30 23:43:28 el-toro-audioteka go-librespot[3953]: time="2025-04-30T23:43:28+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 30 23:43:28 el-toro-audioteka go-librespot[3953]: time="2025-04-30T23:43:28+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 30 23:43:28 el-toro-audioteka go-librespot[3953]: time="2025-04-30T23:43:28+02:00" level=info msg="zeroconf server listening on port 46329" Apr 30 23:43:31 el-toro-audioteka volumio[902]: info: go-librespot daemon successfully initialized Apr 30 23:43:34 el-toro-audioteka volumio[902]: info: Initializing connection to go-librespot Websocket Apr 30 23:43:34 el-toro-audioteka go-librespot[3953]: time="2025-04-30T23:43:34+02:00" level=debug msg="new websocket client" Apr 30 23:43:34 el-toro-audioteka volumio[902]: info: Connection to go-librespot Websocket established Apr 30 23:43:34 el-toro-audioteka volumio[902]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 30 23:43:35 el-toro-audioteka ntpd[779]: Soliciting pool server 155.4.55.243 Apr 30 23:43:36 el-toro-audioteka ntpd[779]: Soliciting pool server 45.83.221.52 Apr 30 23:43:37 el-toro-audioteka volumio[902]: info: Getting Spotify volume Apr 30 23:43:37 el-toro-audioteka volumio[902]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Apr 30 23:43:37 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:43:37 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:43:37 el-toro-audioteka volumio[902]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 30 23:43:37 el-toro-audioteka volumio[902]: SPOTIFY: SPOTIFY VOLUME undefined Apr 30 23:43:37 el-toro-audioteka volumio[902]: SPOTIFY: VOLUMIO VOLUME 100 Apr 30 23:43:37 el-toro-audioteka volumio[902]: info: Aligning Spotify Volume to Volumio Volume Apr 30 23:43:37 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:43:37 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:43:37 el-toro-audioteka volumio[902]: info: Setting Spotify Volume from Volumio: 100 Apr 30 23:43:39 el-toro-audioteka volumio[902]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Apr 30 23:43:39 el-toro-audioteka volumio[902]: info: Sending Spotify command with payload to local API: /player/volume Apr 30 23:43:39 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 30 23:43:39 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 30 23:43:41 el-toro-audioteka ntpd[779]: Soliciting pool server 194.58.206.20 Apr 30 23:43:41 el-toro-audioteka volumio[902]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 30 23:43:42 el-toro-audioteka ntpd[779]: Soliciting pool server 176.126.86.247 Apr 30 23:43:46 el-toro-audioteka ntpd[779]: Soliciting pool server 194.58.200.20 Apr 30 23:43:54 el-toro-audioteka volumio[902]: info: Received OAUTH Data Apr 30 23:43:54 el-toro-audioteka volumio[902]: info: Executing Spotify Oauth Login Apr 30 23:43:54 el-toro-audioteka volumio[902]: info: Saving Spotify Refresh Token Apr 30 23:43:55 el-toro-audioteka sudo[4049]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 30 23:43:55 el-toro-audioteka sudo[4049]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 23:43:55 el-toro-audioteka sudo[4049]: pam_unix(sudo:session): session closed for user root Apr 30 23:43:55 el-toro-audioteka sudo[4051]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 30 23:43:55 el-toro-audioteka sudo[4051]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 23:43:55 el-toro-audioteka sudo[4051]: pam_unix(sudo:session): session closed for user root Apr 30 23:43:55 el-toro-audioteka volumio[902]: verbose: New Socket.io Connection to 192.168.1.68 from 192.168.1.47 UA: Mozilla/5.0 (Linux; Android 16; Pixel 8 Pro Build/BP22.250325.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.111 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetVisibleSources Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: Received Get System Info Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: Discovery: Getting this device information Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: Listing playlists Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Apr 30 23:43:55 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 30 23:43:56 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 30 23:43:57 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Apr 30 23:43:57 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 30 23:43:57 el-toro-audioteka volumio[902]: info: Received Get System Info Apr 30 23:43:57 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 30 23:43:57 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 30 23:43:57 el-toro-audioteka volumio[902]: info: Discovery: Getting this device information Apr 30 23:43:57 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:43:57 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:43:57 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 30 23:43:58 el-toro-audioteka ntpd[779]: Soliciting pool server 176.126.86.247 Apr 30 23:43:58 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 30 23:43:58 el-toro-audioteka volumio[902]: info: Received Get System Info Apr 30 23:43:58 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 30 23:43:58 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 30 23:43:58 el-toro-audioteka volumio[902]: info: Discovery: Getting this device information Apr 30 23:43:58 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:43:58 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:43:58 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 30 23:44:00 el-toro-audioteka volumio[902]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 30 23:44:00 el-toro-audioteka volumio[902]: SPOTIFY: BQCsM_51r20vYnD_-4zMvwZwRV3KgVUvRAgAUtTss3WK7oWD0NdfwRjLBZqQAChasPCZNnAJndyCOJ7MlLL0fntOLXr43L2c4LcpR87YPASpf6ObF5CQFHMuPZzOfQOBQiao5JMdq3OaGTLc3H5Mn4sEi2r47KnI97tKYjBAhNbXMt8ETchfXyhB1YaHvS8MkHLuKxJyXZNnTWQwd5C-G4IFstDESbp5d35L4GczEDa5I-87ZddYCQ1rTQqG78g_uX0j_Hw1xoSf6nXEqimKKnA61ipcNA Apr 30 23:44:00 el-toro-audioteka volumio[902]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 30 23:44:00 el-toro-audioteka volumio[902]: info: New Spotify access token = BQCsM_51r20vYnD_-4zMvwZwRV3KgVUvRAgAUtTss3WK7oWD0NdfwRjLBZqQAChasPCZNnAJndyCOJ7MlLL0fntOLXr43L2c4LcpR87YPASpf6ObF5CQFHMuPZzOfQOBQiao5JMdq3OaGTLc3H5Mn4sEi2r47KnI97tKYjBAhNbXMt8ETchfXyhB1YaHvS8MkHLuKxJyXZNnTWQwd5C-G4IFstDESbp5d35L4GczEDa5I-87ZddYCQ1rTQqG78g_uX0j_Hw1xoSf6nXEqimKKnA61ipcNA Apr 30 23:44:00 el-toro-audioteka volumio[902]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 30 23:44:00 el-toro-audioteka volumio[902]: SPOTIFY: User informations: {"country":"SE","display_name":"stennelunkan","email":"stenne.lundqvist@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/stennelunkan"},"followers":{"href":null,"total":3},"href":"https://api.spotify.com/v1/users/stennelunkan","id":"stennelunkan","images":[],"product":"premium","type":"user","uri":"spotify:user:stennelunkan"} Apr 30 23:44:00 el-toro-audioteka volumio[902]: info: Creating Spotify config file Apr 30 23:44:00 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 30 23:44:00 el-toro-audioteka volumio[902]: info: Spotify config file written Apr 30 23:44:00 el-toro-audioteka sudo[4058]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 30 23:44:00 el-toro-audioteka sudo[4058]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 23:44:00 el-toro-audioteka systemd[1]: Stopping go-librespot Daemon... Apr 30 23:44:00 el-toro-audioteka systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Apr 30 23:44:00 el-toro-audioteka systemd[1]: go-librespot-daemon.service: Succeeded. Apr 30 23:44:00 el-toro-audioteka systemd[1]: Stopped go-librespot Daemon. Apr 30 23:44:00 el-toro-audioteka volumio[902]: info: Connection to go-librespot Websocket closed Apr 30 23:44:00 el-toro-audioteka systemd[1]: Started go-librespot Daemon. Apr 30 23:44:00 el-toro-audioteka go-librespot[4060]: go-librespot daemon starting... Apr 30 23:44:00 el-toro-audioteka sudo[4058]: pam_unix(sudo:session): session closed for user root Apr 30 23:44:00 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:00+02:00" level=info msg="running go-librespot 0.2.0" Apr 30 23:44:00 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:00+02:00" level=debug msg="app state loaded" Apr 30 23:44:00 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:00+02:00" level=debug msg="stored credentials not found" Apr 30 23:44:00 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:00+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 30 23:44:00 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:00+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]" Apr 30 23:44:00 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:00+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Apr 30 23:44:00 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:00+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Apr 30 23:44:00 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:00+02:00" level=info msg="zeroconf server listening on port 33377" Apr 30 23:44:01 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:01+02:00" level=debug msg="obtained new client token: AACWqYSQLez1V7bnsLLsSZfum3kJInKN9V/QRmh4j1AYXYUpEK5RzfF0lsGfAiF697C7+txVH6YQQ7pc7Z8sWDCiKPnYcYZBoB7CucqCV7K0/FFvnjU7QJHY7K60MwqbzehbU82vH1JEO/od3zGliKtNkMphbM5WyKU1xV4FirbmB6k7WEaGHAw2LoQF/Vf2mAVIs8HVyVMFUwV/DK6yfvDK7XNnyo8hoyJJAwoIoh3G0W+gIWq1ZkU=" Apr 30 23:44:01 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:01+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Apr 30 23:44:01 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:01+02:00" level=debug msg="completed keyexchange" Apr 30 23:44:01 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:01+02:00" level=debug msg="completed challenge" Apr 30 23:44:01 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:01+02:00" level=info msg="authenticated AP as stennelunkan" Apr 30 23:44:01 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:01+02:00" level=info msg="authenticated Login5 as stennelunkan" Apr 30 23:44:01 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:01+02:00" level=debug msg="stored credentials for stennelunkan" Apr 30 23:44:01 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:01+02:00" level=debug msg="initializing zeroconf session, username: stennelunkan" Apr 30 23:44:01 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:01+02:00" level=debug msg="dealer connection opened" Apr 30 23:44:01 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:01+02:00" level=trace msg="starting accesspoint recv loop" Apr 30 23:44:01 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:01+02:00" level=trace msg="starting dealer recv loop" Apr 30 23:44:01 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:01+02:00" level=trace msg="received accesspoint ping" Apr 30 23:44:01 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:01+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 30 23:44:01 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:01+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 30 23:44:01 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:01+02:00" level=debug msg="received connection id: M2FhY2QyOTAtNTE1My00Y2YwLWExYzMtNWMwMTBiMGVmNTc3K2RlYWxlcit0Y3A6Ly8wYWNhNTg5Yi5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNzRFQkU5REQ3MjM2M0RGNTVFQzNFNTUxMzEwNUMyRkRFRjlDRjE0RUNEMkY2NEYxNUNEQTcyQUM5RUVCQzVFMg==" Apr 30 23:44:02 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:02+02:00" level=debug msg="put connect state because NEW_DEVICE" Apr 30 23:44:02 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:02+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 30 23:44:02 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:02+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 30 23:44:02 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:02+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 30 23:44:02 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:02+02:00" level=trace msg="received accesspoint pong ack" Apr 30 23:44:03 el-toro-audioteka volumio[902]: info: Initializing connection to go-librespot Websocket Apr 30 23:44:03 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:03+02:00" level=debug msg="new websocket client" Apr 30 23:44:03 el-toro-audioteka volumio[902]: info: Connection to go-librespot Websocket established Apr 30 23:44:03 el-toro-audioteka volumio[902]: info: go-librespot daemon successfully initialized Apr 30 23:44:05 el-toro-audioteka volumio[902]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 30 23:44:05 el-toro-audioteka volumio[902]: SPOTIFY: BQA8GKUpJXXgGqPlPf16kePwyYRWop7lqhP90ptNWgcgkWl7bjOiOMFBe1BjZy8UX9kzB1KymPiidbAr-2HcJly2sEgRuno_okH788udvCos-wL5hgTIyhnngyTz6zHbGHbbe_7Uz9d41cfrIV2cpedYjUTFAgzbMfobNkmyeYZfiKI-3lWIYIjY1PPgeWVDrzhoSMZqgwWvJRCtGuVCK4VpHS5TVqVgySi-2gbWSumRS7Pph-f46rlOR0MRj_-BzFw_wAvQlAdMLhABL-7iTLXxnQsAWw Apr 30 23:44:05 el-toro-audioteka volumio[902]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Apr 30 23:44:05 el-toro-audioteka volumio[902]: info: New Spotify access token = BQA8GKUpJXXgGqPlPf16kePwyYRWop7lqhP90ptNWgcgkWl7bjOiOMFBe1BjZy8UX9kzB1KymPiidbAr-2HcJly2sEgRuno_okH788udvCos-wL5hgTIyhnngyTz6zHbGHbbe_7Uz9d41cfrIV2cpedYjUTFAgzbMfobNkmyeYZfiKI-3lWIYIjY1PPgeWVDrzhoSMZqgwWvJRCtGuVCK4VpHS5TVqVgySi-2gbWSumRS7Pph-f46rlOR0MRj_-BzFw_wAvQlAdMLhABL-7iTLXxnQsAWw Apr 30 23:44:05 el-toro-audioteka volumio[902]: info: Spotify credentials grant success - running version from March 24, 2019 Apr 30 23:44:05 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 30 23:44:05 el-toro-audioteka volumio[902]: SPOTIFY: User informations: {"country":"SE","display_name":"stennelunkan","email":"stenne.lundqvist@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/stennelunkan"},"followers":{"href":null,"total":3},"href":"https://api.spotify.com/v1/users/stennelunkan","id":"stennelunkan","images":[],"product":"premium","type":"user","uri":"spotify:user:stennelunkan"} Apr 30 23:44:05 el-toro-audioteka volumio[902]: info: Spotify Successfully logged in Apr 30 23:44:05 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 30 23:44:05 el-toro-audioteka volumio[902]: info: [1746049445975] CoreMusicLibrary::Adding element Spotify Apr 30 23:44:05 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 30 23:44:05 el-toro-audioteka volumio[902]: Cannot find translation for source Spotify Apr 30 23:44:06 el-toro-audioteka volumio[902]: info: An error occurred while initializing Spotify Browsing facility: TypeError: Cannot read property 'broadcastMessage' of null Apr 30 23:44:06 el-toro-audioteka volumio[902]: info: Getting Spotify volume Apr 30 23:44:06 el-toro-audioteka volumio[902]: info: Spotify volume: 100 Apr 30 23:44:06 el-toro-audioteka volumio[902]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Apr 30 23:44:06 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:44:06 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:44:06 el-toro-audioteka volumio[902]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 30 23:44:06 el-toro-audioteka volumio[902]: info: Initializing connection to go-librespot Websocket Apr 30 23:44:06 el-toro-audioteka go-librespot[4060]: time="2025-04-30T23:44:06+02:00" level=debug msg="new websocket client" Apr 30 23:44:06 el-toro-audioteka volumio[902]: info: Connection to go-librespot Websocket established Apr 30 23:44:09 el-toro-audioteka volumio[902]: info: CALLMETHOD: music_service spop saveGoLibrespotSettings [object Object] Apr 30 23:44:09 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: spop , saveGoLibrespotSettings Apr 30 23:44:09 el-toro-audioteka volumio[902]: info: Creating Spotify config file Apr 30 23:44:09 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 30 23:44:09 el-toro-audioteka volumio[902]: info: Spotify config file written Apr 30 23:44:09 el-toro-audioteka sudo[4084]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 30 23:44:09 el-toro-audioteka sudo[4084]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 30 23:44:09 el-toro-audioteka systemd[1]: Stopping go-librespot Daemon... Apr 30 23:44:09 el-toro-audioteka systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Apr 30 23:44:09 el-toro-audioteka systemd[1]: go-librespot-daemon.service: Succeeded. Apr 30 23:44:09 el-toro-audioteka systemd[1]: Stopped go-librespot Daemon. Apr 30 23:44:09 el-toro-audioteka volumio[902]: info: Getting Spotify volume Apr 30 23:44:09 el-toro-audioteka volumio[902]: (node:902) UnhandledPromiseRejectionWarning: Error: connect ECONNREFUSED 127.0.0.1:9879 Apr 30 23:44:09 el-toro-audioteka volumio[902]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) Apr 30 23:44:09 el-toro-audioteka volumio[902]: (Use `node --trace-warnings ...` to show where the warning was created) Apr 30 23:44:09 el-toro-audioteka volumio[902]: (node:902) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2) Apr 30 23:44:09 el-toro-audioteka volumio[902]: (node:902) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. Apr 30 23:44:09 el-toro-audioteka volumio[902]: info: Connection to go-librespot Websocket closed Apr 30 23:44:09 el-toro-audioteka volumio[902]: info: Connection to go-librespot Websocket closed Apr 30 23:44:09 el-toro-audioteka volumio[902]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Apr 30 23:44:09 el-toro-audioteka systemd[1]: Started go-librespot Daemon. Apr 30 23:44:09 el-toro-audioteka go-librespot[4086]: go-librespot daemon starting... Apr 30 23:44:09 el-toro-audioteka sudo[4084]: pam_unix(sudo:session): session closed for user root Apr 30 23:44:09 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:44:09 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:44:09 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:09+02:00" level=info msg="running go-librespot 0.2.0" Apr 30 23:44:09 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:09+02:00" level=debug msg="app state loaded" Apr 30 23:44:09 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:09+02:00" level=info msg="api server listening on 127.0.0.1:9879" Apr 30 23:44:09 el-toro-audioteka volumio[902]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 30 23:44:09 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:09+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 30 23:44:09 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:09+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Apr 30 23:44:09 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:09+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=info msg="zeroconf server listening on port 40817" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=debug msg="obtained new client token: AACmBgRSWSJo00TJ41Qse47XXSBbCjgpqiJiC0NZEL59Wa1m+KQbq4caakW+72otJnBcsuq7JP3rhBVPo+J0XcsfI26Ri3CjQvWKPsC77yZvaKTcqT/i5IMWrDce0V2LsPudUqmbRoz/XpPDpXklapeDE8gxFcCLfl6WN58B27RJauimjtlf6HksewQyKvLsLGywgzXI6kERhKmNvHW3s/BUuqBEbvfdNT88teHEDGom7O/bQvVI/cE=" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.1.133:4070: connect: connection refused" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=debug msg="connected to ap-gew4.spotify.com:443" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=debug msg="completed keyexchange" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=debug msg="completed challenge" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=info msg="authenticated AP as stennelunkan" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=info msg="authenticated Login5 as stennelunkan" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=debug msg="initializing zeroconf session, username: stennelunkan" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=debug msg="dealer connection opened" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=trace msg="starting accesspoint recv loop" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=trace msg="starting dealer recv loop" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=trace msg="received accesspoint ping" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=debug msg="received connection id: YzEyZjk3YmEtMjhjOS00MWMxLThjY2EtMjljOTY4MWIxZjI2K2RlYWxlcit0Y3A6Ly8wYWNhNTg3Ny5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArOEZFN0VEMEJCRUZEQUZGQjRFODM2NTg2MkFENzc4RDA0MUIxRUFGMTgxODU5NDJBQkJCMDM2OUVEQThFOTgyOA==" Apr 30 23:44:10 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:10+02:00" level=trace msg="received accesspoint pong ack" Apr 30 23:44:11 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:11+02:00" level=debug msg="put connect state because NEW_DEVICE" Apr 30 23:44:12 el-toro-audioteka volumio[902]: info: Initializing connection to go-librespot Websocket Apr 30 23:44:12 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:12+02:00" level=debug msg="new websocket client" Apr 30 23:44:12 el-toro-audioteka volumio[902]: info: Connection to go-librespot Websocket established Apr 30 23:44:12 el-toro-audioteka volumio[902]: info: go-librespot daemon successfully initialized Apr 30 23:44:14 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 30 23:44:14 el-toro-audioteka volumio[902]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 30 23:44:14 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 30 23:44:14 el-toro-audioteka volumio[902]: error: Failed callmethod call: TypeError: Cannot read property 'broadcastMessage' of null Apr 30 23:44:14 el-toro-audioteka volumio[902]: info: Received Get System Version Apr 30 23:44:14 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 30 23:44:14 el-toro-audioteka volumio[902]: info: Received Get System Info Apr 30 23:44:14 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 30 23:44:14 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 30 23:44:14 el-toro-audioteka volumio[902]: info: Discovery: Getting this device information Apr 30 23:44:14 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:44:14 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:44:14 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 30 23:44:15 el-toro-audioteka volumio[902]: info: Getting Spotify volume Apr 30 23:44:15 el-toro-audioteka volumio[902]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Apr 30 23:44:15 el-toro-audioteka volumio[902]: info: Spotify volume: 100 Apr 30 23:44:15 el-toro-audioteka volumio[902]: info: Initializing connection to go-librespot Websocket Apr 30 23:44:15 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:15+02:00" level=debug msg="new websocket client" Apr 30 23:44:15 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:44:15 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:44:15 el-toro-audioteka volumio[902]: info: Connection to go-librespot Websocket established Apr 30 23:44:15 el-toro-audioteka volumio[902]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 30 23:44:18 el-toro-audioteka volumio[902]: info: Getting Spotify volume Apr 30 23:44:18 el-toro-audioteka volumio[902]: info: Spotify volume: 100 Apr 30 23:44:18 el-toro-audioteka volumio[902]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Apr 30 23:44:18 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:44:18 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:44:18 el-toro-audioteka volumio[902]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Apr 30 23:44:27 el-toro-audioteka volumio[902]: verbose: New Socket.io Connection to 192.168.1.68 from 192.168.1.47 UA: Mozilla/5.0 (Linux; Android 16; Pixel 8 Pro Build/BP22.250325.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/135.0.7049.111 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetVisibleSources Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: Received Get System Info Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: Discovery: Getting this device information Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: CoreCommandRouter::volumioGetState Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: CorePlayQueue::getTrack 0 Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: Listing playlists Apr 30 23:44:27 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Apr 30 23:44:38 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Apr 30 23:44:38 el-toro-audioteka volumio[902]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Apr 30 23:44:40 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:40+02:00" level=trace msg="sent dealer ping" Apr 30 23:44:40 el-toro-audioteka go-librespot[4086]: time="2025-04-30T23:44:40+02:00" level=trace msg="received dealer pong" Apr 30 23:44:43 el-toro-audioteka ntpd[779]: Soliciting pool server 31.209.26.42 Apr 30 23:44:48 el-toro-audioteka volumio[902]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/touch_display/volumio/buster/armhf Apr 30 23:44:48 el-toro-audioteka volumio[902]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 30 23:44:48 el-toro-audioteka volumio[902]: TypeError: Cannot read property 'broadcastMessage' of null Apr 30 23:44:48 el-toro-audioteka volumio[902]: at /volumio/app/index.js:1534:32 Apr 30 23:44:48 el-toro-audioteka volumio[902]: at fastMap (/volumio/node_modules/fast.js/array/map.js:21:17) Apr 30 23:44:48 el-toro-audioteka volumio[902]: at Function.fastMap [as map] (/volumio/node_modules/fast.js/map.js:18:12) Apr 30 23:44:48 el-toro-audioteka volumio[902]: at CoreCommandRouter.broadcastMessage (/volumio/app/index.js:1532:13) Apr 30 23:44:48 el-toro-audioteka volumio[902]: at PluginManager.pushMessage (/volumio/app/pluginmanager.js:1594:20) Apr 30 23:44:48 el-toro-audioteka volumio[902]: at PluginManager.installPlugin (/volumio/app/pluginmanager.js:776:8) Apr 30 23:44:48 el-toro-audioteka volumio[902]: at CoreCommandRouter.installPlugin (/volumio/app/index.js:1453:22) Apr 30 23:44:48 el-toro-audioteka volumio[902]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1209:47) Apr 30 23:44:48 el-toro-audioteka volumio[902]: at Socket.emit (events.js:315:20) Apr 30 23:44:48 el-toro-audioteka volumio[902]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Apr 30 23:44:48 el-toro-audioteka volumio[902]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Apr 30 23:44:48 el-toro-audioteka volumio[902]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 30 23:44:49 el-toro-audioteka sudo[4208]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-04-30 23:43 Apr 30 23:44:49 el-toro-audioteka sudo[4208]: 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"