-- Logs begin at Thu 2019-02-14 12:11:58 EET, end at Fri 2025-05-30 12:55:27 EEST. -- May 30 12:54:00 saitis volumio[1030]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/soundcloud/volumio/buster/armhf May 30 12:54:00 saitis volumio[1030]: info: Folder /tmp/plugins removed May 30 12:54:00 saitis volumio[1030]: info: Check plugin dependencies May 30 12:54:00 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 30 12:54:00 saitis volumio[1030]: info: Checking if plugin already exists May 30 12:54:00 saitis volumio[1030]: info: Rename folder May 30 12:54:00 saitis volumio[1030]: info: Folder /tmp/downloaded_plugin.zip removed May 30 12:54:00 saitis volumio[1030]: info: Move to category May 30 12:54:01 saitis volumio[1030]: info: Checking if install.sh is present May 30 12:54:01 saitis volumio[1030]: info: Executing install.sh May 30 12:54:01 saitis sudo[2213]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/soundcloud/install.sh May 30 12:54:01 saitis sudo[2213]: pam_unix(sudo:session): session opened for user root by (uid=0) May 30 12:54:01 saitis sudo[2213]: pam_unix(sudo:session): session closed for user root May 30 12:54:01 saitis volumio[1030]: info: SoundCloud plugin installed May 30 12:54:01 saitis volumio[1030]: Plugin install end detected on script May 30 12:54:01 saitis volumio[1030]: info: Install script completed May 30 12:54:01 saitis volumio[1030]: info: Adding reference to registry May 30 12:54:01 saitis volumio[1030]: info: Done installing plugin. May 30 12:54:01 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 30 12:54:01 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 30 12:54:01 saitis volumio[1030]: info: Folder /tmp/plugins removed May 30 12:54:01 saitis volumio[1030]: info: Folder /tmp/downloaded_plugin.zip removed May 30 12:54:01 saitis volumio[1030]: info: Folder /data/temp removed May 30 12:54:09 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 30 12:54:09 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 30 12:54:09 saitis volumio[1030]: info: Discovery: Getting this device information May 30 12:54:09 saitis volumio[1030]: info: CoreCommandRouter::volumioGetState May 30 12:54:09 saitis volumio[1030]: info: CorePlayQueue::getTrack 0 May 30 12:54:09 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 30 12:54:20 saitis volumio[1030]: info: Downloading plugin at https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/buster/armhf May 30 12:54:22 saitis volumio[1030]: info: END DOWNLOAD: https://plugins.volumio.workers.dev/pluginsv2/downloadLatestStable/spop/volumio/buster/armhf May 30 12:54:22 saitis volumio[1030]: info: Folder /tmp/plugins removed May 30 12:54:22 saitis volumio[1030]: info: Check plugin dependencies May 30 12:54:23 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 30 12:54:23 saitis volumio[1030]: info: Checking if plugin already exists May 30 12:54:23 saitis volumio[1030]: info: Rename folder May 30 12:54:23 saitis volumio[1030]: info: Folder /tmp/downloaded_plugin.zip removed May 30 12:54:23 saitis volumio[1030]: info: Move to category May 30 12:54:26 saitis volumio[1030]: info: Checking if install.sh is present May 30 12:54:26 saitis volumio[1030]: info: Executing install.sh May 30 12:54:26 saitis sudo[2261]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/spop/install.sh May 30 12:54:26 saitis sudo[2261]: pam_unix(sudo:session): session opened for user root by (uid=0) May 30 12:54:26 saitis volumio[1030]: info: Installing Go-librespot May 30 12:54:26 saitis volumio[1030]: info: Checking old vollibrespot installs May 30 12:54:26 saitis systemd[1]: Reloading. May 30 12:54:26 saitis 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 30 12:54:26 saitis systemd[1]: getty@tty1.service: Current command vanished from the unit file, execution of the command list won't be resumed. May 30 12:54:26 saitis volumio[1030]: info: Downloading daemon May 30 12:54:28 saitis volumio[1030]: info: Creating directories May 30 12:54:28 saitis volumio[1030]: info: Creating data directory May 30 12:54:28 saitis volumio[1030]: info: Creating Start Script May 30 12:54:28 saitis systemd[1]: Reloading. May 30 12:54:29 saitis 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 30 12:54:29 saitis sudo[2261]: pam_unix(sudo:session): session closed for user root May 30 12:54:29 saitis volumio[1030]: Plugin install end detected on script May 30 12:54:29 saitis volumio[1030]: info: Install script completed May 30 12:54:29 saitis volumio[1030]: info: Adding reference to registry May 30 12:54:29 saitis volumio[1030]: info: Done installing plugin. May 30 12:54:29 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 30 12:54:29 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 30 12:54:29 saitis volumio[1030]: info: Folder /tmp/plugins removed May 30 12:54:29 saitis volumio[1030]: info: Folder /tmp/downloaded_plugin.zip removed May 30 12:54:29 saitis volumio[1030]: info: Folder /data/temp removed May 30 12:54:32 saitis volumio[1030]: info: Enabling plugin spop May 30 12:54:32 saitis volumio[1030]: info: Loading plugin "spop"... May 30 12:54:32 saitis volumio[1030]: info: PLUGIN START: spop May 30 12:54:32 saitis volumio[1030]: info: Creating Spotify config file May 30 12:54:32 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 30 12:54:32 saitis volumio[1030]: info: Done. May 30 12:54:32 saitis volumio[1030]: info: Spotify config file written May 30 12:54:32 saitis volumio[1030]: info: No need to fix Spotify hosts May 30 12:54:32 saitis sudo[2323]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service May 30 12:54:32 saitis sudo[2323]: pam_unix(sudo:session): session opened for user root by (uid=0) May 30 12:54:32 saitis systemd[1]: Started go-librespot Daemon. May 30 12:54:32 saitis go-librespot[2325]: go-librespot daemon starting... May 30 12:54:32 saitis sudo[2323]: pam_unix(sudo:session): session closed for user root May 30 12:54:32 saitis go-librespot[2325]: time="2025-05-30T12:54:32+03:00" level=info msg="running go-librespot 0.2.0" May 30 12:54:32 saitis go-librespot[2325]: time="2025-05-30T12:54:32+03:00" level=debug msg="no app state found" May 30 12:54:32 saitis go-librespot[2325]: time="2025-05-30T12:54:32+03:00" level=debug msg="stored credentials not found" May 30 12:54:32 saitis go-librespot[2325]: time="2025-05-30T12:54:32+03:00" level=info msg="generated new device id: 09115b0ab5ae7e5c4e23b7e643ad1b966b8f90be" May 30 12:54:32 saitis go-librespot[2325]: time="2025-05-30T12:54:32+03:00" level=info msg="api server listening on 127.0.0.1:9879" May 30 12:54:33 saitis go-librespot[2325]: time="2025-05-30T12:54:33+03:00" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" May 30 12:54:33 saitis go-librespot[2325]: time="2025-05-30T12:54:33+03:00" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" May 30 12:54:33 saitis go-librespot[2325]: time="2025-05-30T12:54:33+03:00" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" May 30 12:54:33 saitis go-librespot[2325]: time="2025-05-30T12:54:33+03:00" level=info msg="zeroconf server listening on port 41995" May 30 12:54:35 saitis volumio[1030]: info: go-librespot daemon successfully initialized May 30 12:54:36 saitis volumio[1030]: info: CoreCommandRouter::volumioGetState May 30 12:54:36 saitis volumio[1030]: info: CorePlayQueue::getTrack 0 May 30 12:54:38 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 30 12:54:38 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 30 12:54:38 saitis volumio[1030]: info: Initializing connection to go-librespot Websocket May 30 12:54:38 saitis go-librespot[2325]: time="2025-05-30T12:54:38+03:00" level=debug msg="new websocket client" May 30 12:54:38 saitis volumio[1030]: info: Connection to go-librespot Websocket established May 30 12:54:39 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 30 12:54:39 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 30 12:54:39 saitis volumio[1030]: info: Discovery: Getting this device information May 30 12:54:39 saitis volumio[1030]: info: CoreCommandRouter::volumioGetState May 30 12:54:39 saitis volumio[1030]: info: CorePlayQueue::getTrack 0 May 30 12:54:39 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 30 12:54:41 saitis volumio[1030]: info: Getting Spotify volume May 30 12:54:41 saitis volumio[1030]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9 May 30 12:54:41 saitis volumio[1030]: info: CoreCommandRouter::volumioGetState May 30 12:54:41 saitis volumio[1030]: info: CorePlayQueue::getTrack 0 May 30 12:54:41 saitis volumio[1030]: SPOTIFY: RECEIVED VOLUMIO VOLUME 46 May 30 12:54:41 saitis volumio[1030]: SPOTIFY: SPOTIFY VOLUME undefined May 30 12:54:41 saitis volumio[1030]: SPOTIFY: VOLUMIO VOLUME 46 May 30 12:54:41 saitis volumio[1030]: info: Aligning Spotify Volume to Volumio Volume May 30 12:54:41 saitis volumio[1030]: info: CoreCommandRouter::volumioGetState May 30 12:54:41 saitis volumio[1030]: info: CorePlayQueue::getTrack 0 May 30 12:54:41 saitis volumio[1030]: info: Setting Spotify Volume from Volumio: 46 May 30 12:54:43 saitis volumio[1030]: info: Enabling plugin soundcloud May 30 12:54:43 saitis volumio[1030]: info: Loading plugin "soundcloud"... May 30 12:54:43 saitis volumio[1030]: info: PLUGIN START: soundcloud May 30 12:54:43 saitis volumio[1030]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 30 12:54:43 saitis volumio[1030]: info: [1748598883658] CoreMusicLibrary::Adding element SoundCloud May 30 12:54:43 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 30 12:54:43 saitis volumio[1030]: Cannot find translation for source SoundCloud May 30 12:54:43 saitis volumio[1030]: info: Done. May 30 12:54:43 saitis volumio[1030]: SPOTIFY: SETTING SPOTIFY VOLUME 46 May 30 12:54:43 saitis volumio[1030]: info: Sending Spotify command with payload to local API: /player/volume May 30 12:54:47 saitis volumio[1030]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:54:52 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 30 12:54:52 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 30 12:54:54 saitis volumio[1030]: info: CoreCommandRouter::volumioGetState May 30 12:54:54 saitis volumio[1030]: info: CorePlayQueue::getTrack 0 May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:54:56 saitis volumio[1030]: info: Retrieving Cloud Streaming UI May 30 12:54:56 saitis volumio[1030]: info: Getting Tidal Cloud Configuration May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:54:56 saitis volumio[1030]: info: Getting Qobuz Cloud Configuration May 30 12:54:56 saitis volumio[1030]: info: Asking plugin for UI Config May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:54:56 saitis volumio[1030]: info: Getting Spotify Cloud Configuration May 30 12:54:56 saitis volumio[1030]: info: Asking plugin for UI Config May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:54:56 saitis volumio[1030]: info: Saving Spotify Acccount May 30 12:54:56 saitis volumio[1030]: info: Got Tidal Cloud Configuration May 30 12:54:56 saitis volumio[1030]: info: Got it May 30 12:54:56 saitis volumio[1030]: info: Got it May 30 12:54:56 saitis volumio[1030]: error: Could not retrieve Spotify Config from plugin Spotify: no section found May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::getUIConfigOnPlugin May 30 12:54:56 saitis volumio[1030]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::volumioGetBrowseSources May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::volumioGetBrowseSources May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::volumioGetBrowseSources May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 30 12:54:56 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares May 30 12:55:00 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 30 12:55:04 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 30 12:55:08 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 30 12:55:09 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 30 12:55:09 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 30 12:55:09 saitis volumio[1030]: info: Discovery: Getting this device information May 30 12:55:09 saitis volumio[1030]: info: CoreCommandRouter::volumioGetState May 30 12:55:09 saitis volumio[1030]: info: CorePlayQueue::getTrack 0 May 30 12:55:09 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 30 12:55:12 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 30 12:55:15 saitis volumio[1030]: info: CoreCommandRouter::volumioGetState May 30 12:55:15 saitis volumio[1030]: info: CorePlayQueue::getTrack 0 May 30 12:55:24 saitis volumio[1030]: info: CoreCommandRouter::volumioGetQueue May 30 12:55:24 saitis volumio[1030]: info: CoreStateMachine::getQueue May 30 12:55:24 saitis volumio[1030]: info: CorePlayQueue::getQueue May 30 12:55:26 saitis volumio[1030]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri May 30 12:55:26 saitis volumio[1030]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 12:55:26 saitis volumio[1030]: TypeError: Cannot read property 'length' of undefined May 30 12:55:26 saitis volumio[1030]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 May 30 12:55:26 saitis volumio[1030]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 May 30 12:55:26 saitis volumio[1030]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) May 30 12:55:26 saitis volumio[1030]: at Parser.emit (events.js:315:20) May 30 12:55:26 saitis volumio[1030]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) May 30 12:55:26 saitis volumio[1030]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) May 30 12:55:26 saitis volumio[1030]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) May 30 12:55:26 saitis volumio[1030]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) May 30 12:55:26 saitis volumio[1030]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) May 30 12:55:26 saitis volumio[1030]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) May 30 12:55:26 saitis volumio[1030]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) May 30 12:55:26 saitis volumio[1030]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) May 30 12:55:26 saitis volumio[1030]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) May 30 12:55:26 saitis volumio[1030]: at IncomingMessage.emit (events.js:327:22) May 30 12:55:26 saitis volumio[1030]: at endReadableNT (internal/streams/readable.js:1327:12) May 30 12:55:26 saitis volumio[1030]: at processTicksAndRejections (internal/process/task_queues.js:80:21) May 30 12:55:26 saitis volumio[1030]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 30 12:55:27 saitis sudo[2477]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-30 12:54 May 30 12:55:27 saitis sudo[2477]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"