-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2024-10-06 16:19:15 CEST. -- Oct 06 16:18:04 volumio ntpd[764]: Soliciting pool server 2a03:8600::cc Oct 06 16:18:05 volumio volumio[858]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Oct 06 16:18:05 volumio volumio[858]: info: CURURI: albums:// Oct 06 16:18:05 volumio volumio[858]: info: listAlbums - loading Albums from cache Oct 06 16:18:05 volumio volumio[858]: info: Preload queue cleared Oct 06 16:18:08 volumio go-librespot[2399]: time="2024-10-06T16:18:08+02:00" level=debug msg="fetched chunk 5/43, size: 524288" uri="spotify:track:2vN0yJIIsjfUE5EgcBT6hf" Oct 06 16:18:10 volumio volumio[858]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 06 16:18:11 volumio volumio[858]: info: Preload queue cleared Oct 06 16:18:12 volumio volumio[858]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 06 16:18:12 volumio volumio[858]: info: Preload queue cleared Oct 06 16:18:12 volumio ntpd[764]: Soliciting pool server 85.24.237.71 Oct 06 16:18:13 volumio volumio[858]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 06 16:18:13 volumio volumio[858]: info: Preload queue cleared Oct 06 16:18:18 volumio volumio[858]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 06 16:18:18 volumio volumio[858]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 06 16:18:18 volumio volumio[858]: TypeError: Cannot read property 'length' of undefined Oct 06 16:18:18 volumio volumio[858]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Oct 06 16:18:18 volumio volumio[858]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Oct 06 16:18:18 volumio volumio[858]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Oct 06 16:18:18 volumio volumio[858]: at Parser.emit (events.js:315:20) Oct 06 16:18:18 volumio volumio[858]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Oct 06 16:18:18 volumio volumio[858]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Oct 06 16:18:18 volumio volumio[858]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Oct 06 16:18:18 volumio volumio[858]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Oct 06 16:18:18 volumio volumio[858]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Oct 06 16:18:18 volumio volumio[858]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Oct 06 16:18:18 volumio volumio[858]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Oct 06 16:18:18 volumio volumio[858]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Oct 06 16:18:18 volumio volumio[858]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Oct 06 16:18:18 volumio volumio[858]: at IncomingMessage.emit (events.js:327:22) Oct 06 16:18:18 volumio volumio[858]: at endReadableNT (internal/streams/readable.js:1327:12) Oct 06 16:18:18 volumio volumio[858]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Oct 06 16:18:18 volumio volumio[858]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 06 16:18:19 volumio sudo[3807]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-06 16:17 Oct 06 16:18:19 volumio sudo[3807]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:19 volumio sudo[3807]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:19 volumio go-librespot[2399]: time="2024-10-06T16:18:19+02:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Oct 06 16:18:19 volumio go-librespot[2399]: time="2024-10-06T16:18:19+02:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Oct 06 16:18:19 volumio volumio-remote-updater[1339]: [2024-10-06 16:18:19] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 06 16:18:19 volumio volumio-remote-updater[1339]: [2024-10-06 16:18:19] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 06 16:18:19 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 06 16:18:19 volumio systemd[1]: upmpdcli.service: Succeeded. Oct 06 16:18:19 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 06 16:18:19 volumio systemd[1]: Started dynamicswap service. Oct 06 16:18:19 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 06 16:18:19 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 06 16:18:19 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 1. Oct 06 16:18:19 volumio systemd[1]: Stopped Volumio Backend Module. Oct 06 16:18:19 volumio systemd[1]: Started Volumio Backend Module. Oct 06 16:18:19 volumio systemd[1]: Started dynamicswap service. Oct 06 16:18:19 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 06 16:18:20 volumio volumio[3821]: info: ------------------------------------------- Oct 06 16:18:20 volumio volumio[3821]: info: ----- Volumio3 ---- Oct 06 16:18:20 volumio volumio[3821]: info: ------------------------------------------- Oct 06 16:18:20 volumio volumio[3821]: info: ----- System startup ---- Oct 06 16:18:20 volumio volumio[3821]: info: ------------------------------------------- Oct 06 16:18:21 volumio volumio[3821]: info: MYVOLUMIO Environment detected Oct 06 16:18:21 volumio volumio[3821]: info: Plugin folders cleanup Oct 06 16:18:21 volumio volumio[3821]: info: Scanning into folder /volumio/app/plugins/ Oct 06 16:18:21 volumio volumio[3821]: info: Scanning category audio_interface Oct 06 16:18:21 volumio volumio[3821]: info: Scanning category miscellanea Oct 06 16:18:21 volumio volumio[3821]: info: Scanning category music_service Oct 06 16:18:21 volumio volumio[3821]: info: Scanning category plugins.json Oct 06 16:18:21 volumio volumio[3821]: info: Scanning category system_controller Oct 06 16:18:21 volumio volumio[3821]: info: Scanning category user_interface Oct 06 16:18:21 volumio volumio[3821]: info: Scanning into folder /data/plugins/ Oct 06 16:18:21 volumio volumio[3821]: info: Scanning category music_service Oct 06 16:18:21 volumio volumio[3821]: info: Plugin folders cleanup completed Oct 06 16:18:21 volumio volumio[3821]: info: ------------------------------------------- Oct 06 16:18:21 volumio volumio[3821]: info: ----- Core plugins startup ---- Oct 06 16:18:21 volumio volumio[3821]: info: ------------------------------------------- Oct 06 16:18:21 volumio volumio[3821]: info: Loading plugins from folder /volumio/app/plugins/ Oct 06 16:18:21 volumio volumio[3821]: info: Adding plugin upnp to MyMusic Plugins Oct 06 16:18:21 volumio volumio[3821]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 06 16:18:21 volumio volumio[3821]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 06 16:18:21 volumio volumio[3821]: info: Loading plugins from folder /data/plugins/ Oct 06 16:18:21 volumio volumio[3821]: info: Loading plugin "system"... Oct 06 16:18:21 volumio volumio[3821]: info: Loading plugin "appearance"... Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "network"... Oct 06 16:18:22 volumio volumio[3821]: info: Refreshing Cached IP Addresses Oct 06 16:18:22 volumio sudo[3848]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 06 16:18:22 volumio sudo[3848]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:22 volumio sudo[3848]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:22 volumio sudo[3850]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 06 16:18:22 volumio sudo[3850]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "services"... Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "alsa_controller"... Oct 06 16:18:22 volumio sudo[3850]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:22 volumio sudo[3853]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 06 16:18:22 volumio sudo[3853]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:22 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "wizard"... Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "networkfs"... Oct 06 16:18:22 volumio volumio[3821]: info: Cannot mount NAS Diskstation at system boot, trial number 1 ,retrying in 5 seconds Oct 06 16:18:22 volumio volumio[3821]: info: Starting Udev Watcher for removable devices Oct 06 16:18:22 volumio volumio[3821]: info: Ignoring mount for partition: boot Oct 06 16:18:22 volumio volumio[3821]: info: Ignoring mount for partition: volumio Oct 06 16:18:22 volumio volumio[3821]: info: Ignoring mount for partition: volumio_data Oct 06 16:18:22 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "volumio_command_line_client"... Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "upnp"... Oct 06 16:18:22 volumio volumio[3821]: info: [1728224302253] Starting Upmpd Daemon Oct 06 16:18:22 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "my_music"... Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "mpd"... Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "upnp_browser"... Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "alarm-clock"... Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "airplay_emulation"... Oct 06 16:18:22 volumio volumio[3821]: info: Starting Shairport Sync Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "last_100"... Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "webradio"... Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "i2s_dacs"... Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "volumiodiscovery"... Oct 06 16:18:22 volumio volumio[3821]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 06 16:18:22 volumio volumio[3821]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 06 16:18:22 volumio volumio[3821]: *** WARNING *** For more information see Oct 06 16:18:22 volumio node[3821]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 06 16:18:22 volumio volumio[3821]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 06 16:18:22 volumio volumio[3821]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 06 16:18:22 volumio volumio[3821]: *** WARNING *** For more information see Oct 06 16:18:22 volumio node[3821]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 06 16:18:22 volumio node[3821]: *** WARNING *** For more information see Oct 06 16:18:22 volumio node[3821]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 06 16:18:22 volumio node[3821]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 06 16:18:22 volumio node[3821]: *** WARNING *** For more information see Oct 06 16:18:22 volumio volumio[3821]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 06 16:18:22 volumio volumio[3821]: info: Discovery: Started advertising with name: Volumio Oct 06 16:18:22 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 06 16:18:22 volumio volumio[3821]: info: Loading plugin "bandcamp"... Oct 06 16:18:23 volumio volumio[3821]: info: Loading plugin "soundcloud"... Oct 06 16:18:23 volumio volumio[3821]: info: Loading plugin "spop"... Oct 06 16:18:24 volumio go-librespot[2399]: time="2024-10-06T16:18:24+02:00" level=debug msg="fetched chunk 6/43, size: 524288" uri="spotify:track:2vN0yJIIsjfUE5EgcBT6hf" Oct 06 16:18:24 volumio volumio[3821]: info: Loading plugin "outputs"... Oct 06 16:18:24 volumio volumio[3821]: info: Loading plugin "albumart"... Oct 06 16:18:24 volumio volumio[3821]: info: Plugin example_plugin is not enabled Oct 06 16:18:24 volumio volumio[3821]: info: Loading plugin "inputs"... Oct 06 16:18:24 volumio volumio[3821]: info: Loading plugin "updater_comm"... Oct 06 16:18:24 volumio volumio[3821]: info: Plugin mpdemulation is not enabled Oct 06 16:18:24 volumio volumio[3821]: info: Loading plugin "rest_api"... Oct 06 16:18:24 volumio volumio[3821]: info: Loading plugin "websocket"... Oct 06 16:18:24 volumio volumio[3821]: info: Starting Socket.io Server version 2.3.0 Oct 06 16:18:24 volumio volumio[3821]: info: Loading i18n strings for locale sv Oct 06 16:18:24 volumio volumio[3821]: Updating browse sources language Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:18:24 volumio volumio-remote-updater[1339]: [2024-10-06 16:18:24] [connect] Successful connection Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::initPlayerControls Oct 06 16:18:24 volumio volumio[3821]: Forking 3 albumart workers Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 06 16:18:24 volumio volumio[3821]: Express server listening on port 3000 Oct 06 16:18:24 volumio volumio[3821]: [Metrics] WebUI: 4s 42.82ms Oct 06 16:18:24 volumio volumio[3821]: info: CoreStateMachine::resetVolumioState Oct 06 16:18:24 volumio volumio[3821]: info: CoreStateMachine::getcurrentVolume Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::volumioRetrievevolume Oct 06 16:18:24 volumio volumio[3821]: info: CoreStateMachine::pushState Oct 06 16:18:24 volumio volumio[3821]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::volumioPushState Oct 06 16:18:24 volumio volumio[3821]: verbose: New Socket.io Connection to 192.168.2.53 from 192.168.2.42 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 1 Oct 06 16:18:24 volumio volumio[3821]: verbose: New Socket.io Connection to 192.168.2.53 from 192.168.2.42 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 2 Oct 06 16:18:24 volumio volumio-remote-updater[1339]: [2024-10-06 16:18:24] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1728224304 101 Oct 06 16:18:24 volumio volumio[3821]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 3 Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:18:24 volumio volumio[3821]: info: Reloading queue from file Oct 06 16:18:24 volumio volumio[3821]: info: CoreStateMachine::setRepeat null single undefined Oct 06 16:18:24 volumio volumio[3821]: info: CoreStateMachine::pushState Oct 06 16:18:24 volumio volumio[3821]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::volumioPushState Oct 06 16:18:24 volumio volumio[3821]: info: CoreStateMachine::setRandom null Oct 06 16:18:24 volumio volumio[3821]: info: CoreStateMachine::pushState Oct 06 16:18:24 volumio volumio[3821]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:24 volumio volumio[3821]: info: CoreCommandRouter::volumioPushState Oct 06 16:18:24 volumio volumio[3821]: info: Setting Device type: Raspberry PI Oct 06 16:18:24 volumio volumio[3821]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 06 16:18:24 volumio volumio[3821]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 Oct 06 16:18:24 volumio volumio[3821]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 06 16:18:24 volumio volumio[3821]: info: Completed loading Core Plugins Oct 06 16:18:24 volumio volumio[3821]: info: Preparing to generate the ALSA configuration file Oct 06 16:18:25 volumio volumio[3821]: info: Asound.conf file unchanged, so no further update is needed Oct 06 16:18:25 volumio volumio[3821]: info: Output device has changed, restarting MPD Oct 06 16:18:25 volumio volumio[3821]: info: Output device has changed, restarting Shairport Sync Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:18:25 volumio sudo[3899]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 06 16:18:25 volumio sudo[3899]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:25 volumio sudo[3900]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 06 16:18:25 volumio sudo[3900]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:25 volumio sudo[3899]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:25 volumio systemd[1]: Stopping Music Player Daemon... Oct 06 16:18:25 volumio volumio[3821]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 06 16:18:25 volumio volumio[3821]: info: ___________ START PLUGINS ___________ Oct 06 16:18:25 volumio volumio[3821]: info: ControllerMpd::onStart: Initializing MPD Oct 06 16:18:25 volumio volumio[3821]: info: Creating MPD Configuration file Oct 06 16:18:25 volumio systemd[1]: mpd.service: Succeeded. Oct 06 16:18:25 volumio systemd[1]: Stopped Music Player Daemon. Oct 06 16:18:25 volumio systemd[1]: Starting Music Player Daemon... Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:18:25 volumio volumio[3821]: info: [1728224305239] CoreMusicLibrary::Adding element Mediaservrar Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:18:25 volumio sudo[3908]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 06 16:18:25 volumio sudo[3908]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:25 volumio sudo[3908]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:18:25 volumio sudo[3906]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 06 16:18:25 volumio sudo[3906]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:25 volumio sudo[3906]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:25 volumio sudo[3910]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 06 16:18:25 volumio sudo[3910]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:25 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Oct 06 16:18:25 volumio systemd[1]: mpd.service: Succeeded. Oct 06 16:18:25 volumio volumio[3821]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:18:25 volumio systemd[1]: Stopped Music Player Daemon. Oct 06 16:18:25 volumio systemd[1]: Starting Music Player Daemon... Oct 06 16:18:25 volumio volumio[3821]: Starting albumart workers Oct 06 16:18:25 volumio volumio[3821]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:18:25 volumio volumio[3821]: info: [1728224305412] CoreMusicLibrary::Adding element Last_100 Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:18:25 volumio volumio[3821]: info: [1728224305417] CoreMusicLibrary::Adding element Webradio Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 06 16:18:25 volumio volumio[3821]: info: Initializing BBC Radios Oct 06 16:18:25 volumio sudo[3918]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 06 16:18:25 volumio sudo[3918]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:25 volumio sudo[3918]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:25 volumio volumio[3821]: Starting albumart workers Oct 06 16:18:25 volumio volumio[3821]: Starting albumart workers Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:18:25 volumio volumio[3821]: info: [1728224305637] CoreMusicLibrary::Adding element Bandcamp Discover Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:18:25 volumio volumio[3821]: Cannot find translation for source Bandcamp Discover Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:18:25 volumio volumio[3821]: info: [1728224305650] CoreMusicLibrary::Adding element SoundCloud Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:18:25 volumio volumio[3821]: Cannot find translation for source Bandcamp Discover Oct 06 16:18:25 volumio volumio[3821]: Cannot find translation for source SoundCloud Oct 06 16:18:25 volumio volumio[3821]: info: Creating Spotify config file Oct 06 16:18:25 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:25 volumio volumio[3821]: info: Volumio Calling Home Oct 06 16:18:25 volumio sudo[3853]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:26 volumio volumio[3821]: info: Discovery: adding bdec9109-a559-4acf-9692-dc69c4c6c743 Oct 06 16:18:26 volumio volumio[3821]: info: Discovery: Found device Volumio Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::volumioGetState Oct 06 16:18:26 volumio volumio[3821]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:26 volumio volumio[3821]: info: MPD Permissions set Oct 06 16:18:26 volumio volumio[3821]: info: MPD Permissions set Oct 06 16:18:26 volumio volumio[3821]: info: Spotify config file written Oct 06 16:18:26 volumio volumio[3821]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:26 volumio sudo[3962]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 06 16:18:26 volumio sudo[3962]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:26 volumio systemd[1]: Stopping go-librespot Daemon... Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Oct 06 16:18:26 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Oct 06 16:18:26 volumio systemd[1]: Stopped go-librespot Daemon. Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:26 volumio volumio[3821]: info: No need to fix Spotify hosts Oct 06 16:18:26 volumio systemd[1]: Started go-librespot Daemon. Oct 06 16:18:26 volumio go-librespot[3968]: Librespot-go daemon starting... Oct 06 16:18:26 volumio sudo[3962]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:26 volumio go-librespot[3968]: time="2024-10-06T16:18:26+02:00" level=info msg="generated new device id: 5404c12183b748e0c7670619c743bccadbc9dd24" Oct 06 16:18:26 volumio go-librespot[3968]: time="2024-10-06T16:18:26+02:00" level=debug msg="stored credentials found for gronk" Oct 06 16:18:26 volumio volumio[3821]: info: Starting Shairport Sync Oct 06 16:18:26 volumio volumio[3821]: info: Starting Shairport Sync Oct 06 16:18:26 volumio volumio[3821]: info: Starting Shairport Sync Oct 06 16:18:26 volumio sudo[3980]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 06 16:18:26 volumio sudo[3980]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:26 volumio sudo[3982]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 06 16:18:26 volumio sudo[3982]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::volumioGetState Oct 06 16:18:26 volumio volumio[3821]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:26 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 06 16:18:26 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 06 16:18:26 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 06 16:18:26 volumio sudo[3985]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 06 16:18:26 volumio sudo[3985]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:26 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 06 16:18:26 volumio sudo[3980]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:26 volumio volumio[3821]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 06 16:18:26 volumio volumio[3821]: SPOTIFY: BQDgC9pTMMOjLaNcYb7Xji_Gn7hALh58cookPgCPd0kPtensaJZ9k_VI2nojQujygSzkjvl8fa8fdmmM_s7W_WPVgNBcqPdek47gX1DvmrRdMc1Hmp1qESkAHN6-Ebg8wgJvsc9f6AfhQfZ2fGTASQygE8effkwinicGQPg7lRMin4sEz2FObX5T3lS6IWZdWYPRcj1OaQmXIh4pOHBzWzkiLUB3xEgOeo_9nHlex-M-xTdswOiZ Oct 06 16:18:26 volumio volumio[3821]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 06 16:18:26 volumio volumio[3821]: info: New Spotify access token = BQDgC9pTMMOjLaNcYb7Xji_Gn7hALh58cookPgCPd0kPtensaJZ9k_VI2nojQujygSzkjvl8fa8fdmmM_s7W_WPVgNBcqPdek47gX1DvmrRdMc1Hmp1qESkAHN6-Ebg8wgJvsc9f6AfhQfZ2fGTASQygE8effkwinicGQPg7lRMin4sEz2FObX5T3lS6IWZdWYPRcj1OaQmXIh4pOHBzWzkiLUB3xEgOeo_9nHlex-M-xTdswOiZ Oct 06 16:18:26 volumio volumio[3821]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 06 16:18:26 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 06 16:18:26 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 06 16:18:26 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 06 16:18:26 volumio mpd[3925]: Oct 06 16:18 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 06 16:18:26 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 06 16:18:26 volumio go-librespot[3968]: time="2024-10-06T16:18:26+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]" Oct 06 16:18:26 volumio go-librespot[3968]: time="2024-10-06T16:18:26+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]" Oct 06 16:18:26 volumio go-librespot[3968]: time="2024-10-06T16:18:26+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]" Oct 06 16:18:26 volumio sudo[3982]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:26 volumio systemd[1]: Started Music Player Daemon. Oct 06 16:18:26 volumio sudo[3985]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:26 volumio go-librespot[3968]: time="2024-10-06T16:18:26+02:00" level=debug msg="zeroconf server listening on port 35457" Oct 06 16:18:26 volumio sudo[3910]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:26 volumio sudo[3900]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:26 volumio volumio[3821]: info: Shairport-Sync Started Oct 06 16:18:26 volumio volumio[3821]: Error adding Membership: Error: addMembership EINVAL Oct 06 16:18:26 volumio volumio[3821]: info: Completed starting Core Plugins Oct 06 16:18:26 volumio volumio[3821]: info: ------------------------------------------- Oct 06 16:18:26 volumio volumio[3821]: info: ----- MyVolumio plugins startup ---- Oct 06 16:18:26 volumio volumio[3821]: info: ------------------------------------------- Oct 06 16:18:26 volumio volumio[3821]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 06 16:18:26 volumio volumio[3821]: info: Shairport-Sync Started Oct 06 16:18:26 volumio volumio[3821]: info: Shairport-Sync Started Oct 06 16:18:26 volumio go-librespot[3968]: time="2024-10-06T16:18:26+02:00" level=debug msg="obtained new client token: AADHGqsOIE+ykYWHtGbl7YjUEEt7BUjoi4gL0n8FrLH4la1tPsf1EgMLi5+jJ1I4euqrv9Tuwmm3X/mBBQqyA9oegc+Yhub73wZMP4tpwtGTiiUoskxvF1zPDhfbQyWYY4n7P1PlH9t+Qz++AE/X93QMiTFZUvHryRsmgD/UHA9fin4d0/0yg6hkK2eHt+Ev7b5H1hhkXJsxFYn1wmfGMtQl3cjtHR4H6ukOoNMTCv2vhH902/Eaw3KaS4QxPg==" Oct 06 16:18:26 volumio volumio[3821]: error: MPD error: The expression evaluated to a falsy value: Oct 06 16:18:26 volumio volumio[3821]: assert.ok(self.idling) Oct 06 16:18:26 volumio volumio[3821]: error: The expression evaluated to a falsy value: Oct 06 16:18:26 volumio volumio[3821]: assert.ok(self.idling) Oct 06 16:18:26 volumio volumio[3821]: info: MPD running with PID3925 Oct 06 16:18:26 volumio volumio[3821]: ,establishing connection Oct 06 16:18:26 volumio volumio[3821]: error: updateQueue error: null Oct 06 16:18:26 volumio volumio[3821]: error: updateQueue error: null Oct 06 16:18:26 volumio go-librespot[3968]: time="2024-10-06T16:18:26+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 06 16:18:26 volumio go-librespot[3968]: time="2024-10-06T16:18:26+02:00" level=debug msg="completed keyexchange" Oct 06 16:18:26 volumio volumio[3821]: SPOTIFY: User informations: {"display_name":"gronk","external_urls":{"spotify":"https://open.spotify.com/user/gronk"},"href":"https://api.spotify.com/v1/users/gronk","id":"gronk","images":[],"type":"user","uri":"spotify:user:gronk","followers":{"href":null,"total":3},"country":"SE","product":"premium","explicit_content":{"filter_enabled":false,"filter_locked":false},"email":"maglar@me.com"} Oct 06 16:18:26 volumio volumio[3821]: info: Spotify Successfully logged in Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:18:26 volumio volumio[3821]: info: [1728224306912] CoreMusicLibrary::Adding element Spotify Oct 06 16:18:26 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:18:26 volumio volumio[3821]: Cannot find translation for source Bandcamp Discover Oct 06 16:18:26 volumio volumio[3821]: Cannot find translation for source SoundCloud Oct 06 16:18:26 volumio volumio[3821]: Cannot find translation for source Spotify Oct 06 16:18:27 volumio volumio[3821]: info: Cannot mount NAS Diskstation at system boot, trial number 2 ,retrying in 5 seconds Oct 06 16:18:27 volumio go-librespot[3968]: time="2024-10-06T16:18:27+02:00" level=debug msg="completed challenge" Oct 06 16:18:27 volumio go-librespot[3968]: time="2024-10-06T16:18:27+02:00" level=debug msg="authenticated as gronk" Oct 06 16:18:27 volumio go-librespot[3968]: time="2024-10-06T16:18:27+02:00" level=debug msg="authenticated as gronk" Oct 06 16:18:27 volumio go-librespot[3968]: time="2024-10-06T16:18:27+02:00" level=debug msg="dealer connection opened" Oct 06 16:18:27 volumio go-librespot[3968]: time="2024-10-06T16:18:27+02:00" level=debug msg="initializing zeroconf session, username: gronk" Oct 06 16:18:27 volumio go-librespot[3968]: time="2024-10-06T16:18:27+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 06 16:18:27 volumio go-librespot[3968]: time="2024-10-06T16:18:27+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 06 16:18:27 volumio go-librespot[3968]: time="2024-10-06T16:18:27+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 06 16:18:27 volumio go-librespot[3968]: time="2024-10-06T16:18:27+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 06 16:18:27 volumio go-librespot[3968]: time="2024-10-06T16:18:27+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 493" Oct 06 16:18:27 volumio go-librespot[3968]: time="2024-10-06T16:18:27+02:00" level=debug msg="autoplay enabled: false" Oct 06 16:18:27 volumio go-librespot[3968]: time="2024-10-06T16:18:27+02:00" level=debug msg="received connection id: MjRiNTJjOTEtNjZhYi00YjA0LTljZjctZTJjODUzYjhkMGNlK2RlYWxlcit0Y3A6Ly8wYWNhNTg0Mi5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArMzQ1OEFENThFQjU1Qjg5N0E1MDg1MkM1MjBEMTg4N0I2ODQwN0NDOEVCQ0VCMkQwQkREOUM5ODZERTM4QUJBNg==" Oct 06 16:18:27 volumio go-librespot[3968]: time="2024-10-06T16:18:27+02:00" level=debug msg="put connect state because NEW_DEVICE" Oct 06 16:18:28 volumio volumio[3821]: verbose: New Socket.io Connection to 192.168.2.53 from 192.168.2.42 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 5 Oct 06 16:18:28 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 06 16:18:28 volumio volumio[3821]: info: CoreCommandRouter::volumioGetVisibleSources Oct 06 16:18:28 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:18:28 volumio volumio[3821]: info: CoreCommandRouter::volumioGetState Oct 06 16:18:28 volumio volumio[3821]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:28 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 06 16:18:28 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 06 16:18:28 volumio volumio[3821]: info: Received Get System Info Oct 06 16:18:28 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 06 16:18:28 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 06 16:18:28 volumio volumio[3821]: info: Discovery: Getting this device information Oct 06 16:18:28 volumio volumio[3821]: info: CoreCommandRouter::volumioGetState Oct 06 16:18:28 volumio volumio[3821]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:28 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 06 16:18:28 volumio volumio[3821]: info: CoreCommandRouter::volumioGetState Oct 06 16:18:28 volumio volumio[3821]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:28 volumio volumio[3821]: info: Listing playlists Oct 06 16:18:28 volumio volumio[3821]: info: CoreCommandRouter::volumioGetQueue Oct 06 16:18:28 volumio volumio[3821]: info: CoreStateMachine::getQueue Oct 06 16:18:28 volumio volumio[3821]: info: CorePlayQueue::getQueue Oct 06 16:18:29 volumio volumio[3821]: info: go-librespot daemon successfully initialized Oct 06 16:18:31 volumio volumio[3821]: info: Volumio called home Oct 06 16:18:31 volumio volumio[3821]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 06 16:18:31 volumio volumio[3821]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 06 16:18:31 volumio volumio[3821]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 06 16:18:31 volumio volumio[3821]: TypeError: Cannot read property 'length' of undefined Oct 06 16:18:31 volumio volumio[3821]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Oct 06 16:18:31 volumio volumio[3821]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Oct 06 16:18:31 volumio volumio[3821]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Oct 06 16:18:31 volumio volumio[3821]: at Parser.emit (events.js:315:20) Oct 06 16:18:31 volumio volumio[3821]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Oct 06 16:18:31 volumio volumio[3821]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Oct 06 16:18:31 volumio volumio[3821]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Oct 06 16:18:31 volumio volumio[3821]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Oct 06 16:18:31 volumio volumio[3821]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Oct 06 16:18:31 volumio volumio[3821]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Oct 06 16:18:31 volumio volumio[3821]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Oct 06 16:18:31 volumio volumio[3821]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Oct 06 16:18:31 volumio volumio[3821]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Oct 06 16:18:31 volumio volumio[3821]: at IncomingMessage.emit (events.js:327:22) Oct 06 16:18:31 volumio volumio[3821]: at endReadableNT (internal/streams/readable.js:1327:12) Oct 06 16:18:31 volumio volumio[3821]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Oct 06 16:18:31 volumio volumio[3821]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 06 16:18:32 volumio sudo[4010]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-06 16:17 Oct 06 16:18:32 volumio sudo[4010]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:32 volumio sudo[4010]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:32 volumio volumio-remote-updater[1339]: [2024-10-06 16:18:32] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 06 16:18:32 volumio volumio-remote-updater[1339]: [2024-10-06 16:18:32] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 06 16:18:32 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 06 16:18:32 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 06 16:18:32 volumio systemd[1]: Started dynamicswap service. Oct 06 16:18:32 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 06 16:18:32 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 06 16:18:32 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Oct 06 16:18:32 volumio systemd[1]: Stopped Volumio Backend Module. Oct 06 16:18:32 volumio systemd[1]: Started Volumio Backend Module. Oct 06 16:18:32 volumio systemd[1]: Started dynamicswap service. Oct 06 16:18:32 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 06 16:18:33 volumio volumio[4021]: info: ------------------------------------------- Oct 06 16:18:33 volumio volumio[4021]: info: ----- Volumio3 ---- Oct 06 16:18:33 volumio volumio[4021]: info: ------------------------------------------- Oct 06 16:18:33 volumio volumio[4021]: info: ----- System startup ---- Oct 06 16:18:33 volumio volumio[4021]: info: ------------------------------------------- Oct 06 16:18:34 volumio volumio[4021]: info: MYVOLUMIO Environment detected Oct 06 16:18:34 volumio volumio[4021]: info: Plugin folders cleanup Oct 06 16:18:34 volumio volumio[4021]: info: Scanning into folder /volumio/app/plugins/ Oct 06 16:18:34 volumio volumio[4021]: info: Scanning category audio_interface Oct 06 16:18:34 volumio volumio[4021]: info: Scanning category miscellanea Oct 06 16:18:34 volumio volumio[4021]: info: Scanning category music_service Oct 06 16:18:34 volumio volumio[4021]: info: Scanning category plugins.json Oct 06 16:18:34 volumio volumio[4021]: info: Scanning category system_controller Oct 06 16:18:34 volumio volumio[4021]: info: Scanning category user_interface Oct 06 16:18:34 volumio volumio[4021]: info: Scanning into folder /data/plugins/ Oct 06 16:18:34 volumio volumio[4021]: info: Scanning category music_service Oct 06 16:18:34 volumio volumio[4021]: info: Plugin folders cleanup completed Oct 06 16:18:34 volumio volumio[4021]: info: ------------------------------------------- Oct 06 16:18:34 volumio volumio[4021]: info: ----- Core plugins startup ---- Oct 06 16:18:34 volumio volumio[4021]: info: ------------------------------------------- Oct 06 16:18:34 volumio volumio[4021]: info: Loading plugins from folder /volumio/app/plugins/ Oct 06 16:18:34 volumio volumio[4021]: info: Adding plugin upnp to MyMusic Plugins Oct 06 16:18:34 volumio volumio[4021]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 06 16:18:34 volumio volumio[4021]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 06 16:18:34 volumio volumio[4021]: info: Loading plugins from folder /data/plugins/ Oct 06 16:18:34 volumio volumio[4021]: info: Loading plugin "system"... Oct 06 16:18:34 volumio volumio[4021]: info: Loading plugin "appearance"... Oct 06 16:18:34 volumio volumio[4021]: info: Loading plugin "network"... Oct 06 16:18:34 volumio volumio[4021]: info: Refreshing Cached IP Addresses Oct 06 16:18:34 volumio sudo[4048]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 06 16:18:34 volumio sudo[4048]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:34 volumio sudo[4048]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:34 volumio sudo[4050]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 06 16:18:34 volumio sudo[4050]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:34 volumio volumio[4021]: info: Loading plugin "services"... Oct 06 16:18:34 volumio volumio[4021]: info: Loading plugin "alsa_controller"... Oct 06 16:18:34 volumio sudo[4050]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:34 volumio sudo[4053]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 06 16:18:34 volumio sudo[4053]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:34 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 06 16:18:34 volumio volumio[4021]: info: Loading plugin "wizard"... Oct 06 16:18:34 volumio volumio[4021]: info: Loading plugin "networkfs"... Oct 06 16:18:34 volumio volumio[4021]: info: Cannot mount NAS Diskstation at system boot, trial number 1 ,retrying in 5 seconds Oct 06 16:18:34 volumio volumio[4021]: info: Starting Udev Watcher for removable devices Oct 06 16:18:34 volumio volumio[4021]: info: Ignoring mount for partition: boot Oct 06 16:18:34 volumio volumio[4021]: info: Ignoring mount for partition: volumio Oct 06 16:18:34 volumio volumio[4021]: info: Ignoring mount for partition: volumio_data Oct 06 16:18:34 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 06 16:18:34 volumio volumio[4021]: info: Loading plugin "volumio_command_line_client"... Oct 06 16:18:34 volumio volumio[4021]: info: Loading plugin "upnp"... Oct 06 16:18:34 volumio volumio[4021]: info: [1728224314869] Starting Upmpd Daemon Oct 06 16:18:34 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 06 16:18:34 volumio volumio[4021]: info: Loading plugin "my_music"... Oct 06 16:18:34 volumio volumio[4021]: info: Loading plugin "mpd"... Oct 06 16:18:35 volumio volumio[4021]: info: Loading plugin "upnp_browser"... Oct 06 16:18:35 volumio volumio[4021]: info: Loading plugin "alarm-clock"... Oct 06 16:18:35 volumio volumio[4021]: info: Loading plugin "airplay_emulation"... Oct 06 16:18:35 volumio volumio[4021]: info: Starting Shairport Sync Oct 06 16:18:35 volumio volumio[4021]: info: Loading plugin "last_100"... Oct 06 16:18:35 volumio volumio[4021]: info: Loading plugin "webradio"... Oct 06 16:18:35 volumio volumio[4021]: info: Loading plugin "i2s_dacs"... Oct 06 16:18:35 volumio volumio[4021]: info: Loading plugin "volumiodiscovery"... Oct 06 16:18:35 volumio volumio[4021]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 06 16:18:35 volumio volumio[4021]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 06 16:18:35 volumio node[4021]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 06 16:18:35 volumio volumio[4021]: *** WARNING *** For more information see Oct 06 16:18:35 volumio volumio[4021]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 06 16:18:35 volumio volumio[4021]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 06 16:18:35 volumio volumio[4021]: *** WARNING *** For more information see Oct 06 16:18:35 volumio node[4021]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 06 16:18:35 volumio node[4021]: *** WARNING *** For more information see Oct 06 16:18:35 volumio node[4021]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 06 16:18:35 volumio node[4021]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 06 16:18:35 volumio node[4021]: *** WARNING *** For more information see Oct 06 16:18:35 volumio volumio[4021]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 06 16:18:35 volumio volumio[4021]: info: Discovery: Started advertising with name: Volumio Oct 06 16:18:35 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 06 16:18:35 volumio volumio[4021]: info: Loading plugin "bandcamp"... Oct 06 16:18:36 volumio volumio[4021]: info: Loading plugin "soundcloud"... Oct 06 16:18:36 volumio volumio[4021]: info: Loading plugin "spop"... Oct 06 16:18:36 volumio volumio[4021]: info: Loading plugin "outputs"... Oct 06 16:18:36 volumio volumio[4021]: info: Loading plugin "albumart"... Oct 06 16:18:36 volumio volumio[4021]: info: Plugin example_plugin is not enabled Oct 06 16:18:36 volumio volumio[4021]: info: Loading plugin "inputs"... Oct 06 16:18:36 volumio volumio[4021]: info: Loading plugin "updater_comm"... Oct 06 16:18:37 volumio volumio[4021]: info: Plugin mpdemulation is not enabled Oct 06 16:18:37 volumio volumio[4021]: info: Loading plugin "rest_api"... Oct 06 16:18:37 volumio volumio[4021]: info: Loading plugin "websocket"... Oct 06 16:18:37 volumio volumio[4021]: info: Starting Socket.io Server version 2.3.0 Oct 06 16:18:37 volumio volumio[4021]: info: Loading i18n strings for locale sv Oct 06 16:18:37 volumio volumio[4021]: Updating browse sources language Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:18:37 volumio volumio[4021]: Forking 3 albumart workers Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::initPlayerControls Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: Express server listening on port 3000 Oct 06 16:18:37 volumio volumio[4021]: [Metrics] WebUI: 3s 841.39ms Oct 06 16:18:37 volumio volumio[4021]: info: CoreStateMachine::resetVolumioState Oct 06 16:18:37 volumio volumio[4021]: info: CoreStateMachine::getcurrentVolume Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::volumioRetrievevolume Oct 06 16:18:37 volumio volumio[4021]: info: CoreStateMachine::pushState Oct 06 16:18:37 volumio volumio[4021]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::volumioPushState Oct 06 16:18:37 volumio volumio-remote-updater[1339]: [2024-10-06 16:18:37] [connect] Successful connection Oct 06 16:18:37 volumio volumio[4021]: verbose: New Socket.io Connection to 192.168.2.53 from 192.168.2.42 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 1 Oct 06 16:18:37 volumio volumio[4021]: verbose: New Socket.io Connection to 192.168.2.53 from 192.168.2.42 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 2 Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: info: Reloading queue from file Oct 06 16:18:37 volumio volumio-remote-updater[1339]: [2024-10-06 16:18:37] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1728224317 101 Oct 06 16:18:37 volumio volumio[4021]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 3 Oct 06 16:18:37 volumio volumio[4021]: info: CoreStateMachine::setRepeat null single undefined Oct 06 16:18:37 volumio volumio[4021]: info: CoreStateMachine::pushState Oct 06 16:18:37 volumio volumio[4021]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::volumioPushState Oct 06 16:18:37 volumio volumio[4021]: info: CoreStateMachine::setRandom null Oct 06 16:18:37 volumio volumio[4021]: info: CoreStateMachine::pushState Oct 06 16:18:37 volumio volumio[4021]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::volumioPushState Oct 06 16:18:37 volumio volumio[4021]: info: Setting Device type: Raspberry PI Oct 06 16:18:37 volumio volumio[4021]: info: Completed loading Core Plugins Oct 06 16:18:37 volumio volumio[4021]: info: Preparing to generate the ALSA configuration file Oct 06 16:18:37 volumio volumio[4021]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 06 16:18:37 volumio volumio[4021]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 Oct 06 16:18:37 volumio volumio[4021]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 06 16:18:37 volumio volumio[4021]: info: Asound.conf file unchanged, so no further update is needed Oct 06 16:18:37 volumio volumio[4021]: info: Output device has changed, restarting MPD Oct 06 16:18:37 volumio volumio[4021]: info: Output device has changed, restarting Shairport Sync Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:18:37 volumio sudo[4097]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 06 16:18:37 volumio sudo[4097]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:37 volumio sudo[4097]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:37 volumio sudo[4099]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 06 16:18:37 volumio sudo[4099]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:37 volumio volumio[4021]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 06 16:18:37 volumio volumio[4021]: info: ___________ START PLUGINS ___________ Oct 06 16:18:37 volumio volumio[4021]: info: ControllerMpd::onStart: Initializing MPD Oct 06 16:18:37 volumio volumio[4021]: info: Creating MPD Configuration file Oct 06 16:18:37 volumio systemd[1]: Stopping Music Player Daemon... Oct 06 16:18:37 volumio systemd[1]: mpd.service: Succeeded. Oct 06 16:18:37 volumio systemd[1]: Stopped Music Player Daemon. Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:18:37 volumio volumio[4021]: info: [1728224317689] CoreMusicLibrary::Adding element Mediaservrar Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:18:37 volumio sudo[4107]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 06 16:18:37 volumio sudo[4107]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:18:37 volumio sudo[4107]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:37 volumio systemd[1]: Starting Music Player Daemon... Oct 06 16:18:37 volumio sudo[4110]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 06 16:18:37 volumio sudo[4110]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:37 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 06 16:18:37 volumio systemd[1]: mpd.service: Succeeded. Oct 06 16:18:37 volumio systemd[1]: Stopped Music Player Daemon. Oct 06 16:18:37 volumio systemd[1]: Starting Music Player Daemon... Oct 06 16:18:37 volumio volumio[4021]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:18:37 volumio volumio[4021]: info: [1728224317831] CoreMusicLibrary::Adding element Last_100 Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:18:37 volumio volumio[4021]: info: [1728224317834] CoreMusicLibrary::Adding element Webradio Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 06 16:18:37 volumio volumio[4021]: info: Initializing BBC Radios Oct 06 16:18:37 volumio sudo[4115]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 06 16:18:37 volumio sudo[4115]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:37 volumio sudo[4115]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:37 volumio volumio[4021]: Starting albumart workers Oct 06 16:18:37 volumio volumio[4021]: Starting albumart workers Oct 06 16:18:37 volumio volumio[4021]: Starting albumart workers Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:18:37 volumio volumio[4021]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:18:38 volumio volumio[4021]: info: [1728224318005] CoreMusicLibrary::Adding element Bandcamp Discover Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:18:38 volumio volumio[4021]: Cannot find translation for source Bandcamp Discover Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:18:38 volumio volumio[4021]: info: [1728224318017] CoreMusicLibrary::Adding element SoundCloud Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:18:38 volumio volumio[4021]: Cannot find translation for source Bandcamp Discover Oct 06 16:18:38 volumio volumio[4021]: Cannot find translation for source SoundCloud Oct 06 16:18:38 volumio volumio[4021]: info: Creating Spotify config file Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: Volumio Calling Home Oct 06 16:18:38 volumio volumio[4021]: info: Discovery: adding bdec9109-a559-4acf-9692-dc69c4c6c743 Oct 06 16:18:38 volumio volumio[4021]: info: Discovery: Found device Volumio Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::volumioGetState Oct 06 16:18:38 volumio volumio[4021]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:38 volumio sudo[4053]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:38 volumio volumio[4021]: info: MPD Permissions set Oct 06 16:18:38 volumio volumio[4021]: info: MPD Permissions set Oct 06 16:18:38 volumio volumio[4021]: info: Spotify config file written Oct 06 16:18:38 volumio sudo[4151]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 06 16:18:38 volumio sudo[4151]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:38 volumio systemd[1]: Stopping go-librespot Daemon... Oct 06 16:18:38 volumio volumio[4021]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 06 16:18:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Oct 06 16:18:38 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Oct 06 16:18:38 volumio systemd[1]: Stopped go-librespot Daemon. Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio systemd[1]: Started go-librespot Daemon. Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio go-librespot[4161]: Librespot-go daemon starting... Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio sudo[4151]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:38 volumio go-librespot[4161]: time="2024-10-06T16:18:38+02:00" level=info msg="generated new device id: 1b2b776c9f39d23db5baed0a54a737cbd36d9279" Oct 06 16:18:38 volumio go-librespot[4161]: time="2024-10-06T16:18:38+02:00" level=debug msg="stored credentials found for gronk" Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:18:38 volumio volumio[4021]: info: No need to fix Spotify hosts Oct 06 16:18:38 volumio volumio[4021]: info: Volumio called home Oct 06 16:18:38 volumio volumio[4021]: verbose: New Socket.io Connection to 192.168.2.53 from 192.168.2.42 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 5 Oct 06 16:18:38 volumio volumio[4021]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 06 16:18:38 volumio volumio[4021]: SPOTIFY: BQDOKqaaVnk4xXjgxh1Z7XBfI9kghTKYpd0xzdsnQDU_pPRzqHhHS4LY4V0BpiPnFMCYzAWBcyQfccF1cmLpc5E38LRsMjpc2Q1VWCluZNfBBMeTJOwW2tOGM3kX3goDTlbiPf1kzD_F39SKw1szhwC9gtiqwPsrKt_PXxh5owtEw551D_FUgtetUR98dE8Wkg_YG8YHueNkvle-oJkT1KxHXnC0jdbQ496_lGUrFTujkmyFNYcs Oct 06 16:18:38 volumio volumio[4021]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 06 16:18:38 volumio volumio[4021]: info: New Spotify access token = BQDOKqaaVnk4xXjgxh1Z7XBfI9kghTKYpd0xzdsnQDU_pPRzqHhHS4LY4V0BpiPnFMCYzAWBcyQfccF1cmLpc5E38LRsMjpc2Q1VWCluZNfBBMeTJOwW2tOGM3kX3goDTlbiPf1kzD_F39SKw1szhwC9gtiqwPsrKt_PXxh5owtEw551D_FUgtetUR98dE8Wkg_YG8YHueNkvle-oJkT1KxHXnC0jdbQ496_lGUrFTujkmyFNYcs Oct 06 16:18:38 volumio volumio[4021]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 06 16:18:38 volumio go-librespot[4161]: time="2024-10-06T16:18:38+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-gae2.spotify.com:80]" Oct 06 16:18:38 volumio go-librespot[4161]: time="2024-10-06T16:18:38+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 06 16:18:38 volumio go-librespot[4161]: time="2024-10-06T16:18:38+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 06 16:18:38 volumio volumio[4021]: info: Starting Shairport Sync Oct 06 16:18:38 volumio go-librespot[4161]: time="2024-10-06T16:18:38+02:00" level=debug msg="zeroconf server listening on port 44385" Oct 06 16:18:38 volumio volumio[4021]: info: Starting Shairport Sync Oct 06 16:18:38 volumio sudo[4178]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 06 16:18:38 volumio sudo[4178]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:38 volumio volumio[4021]: info: Starting Shairport Sync Oct 06 16:18:38 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 06 16:18:38 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 06 16:18:38 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 06 16:18:38 volumio sudo[4181]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 06 16:18:38 volumio go-librespot[4161]: time="2024-10-06T16:18:38+02:00" level=debug msg="obtained new client token: AADKTXp4ttRe1mIQxw/TEo08/n5P4Vzv3IVjpFxhB7EZHOVkrF+PtRQIMpYplSrewlYwf8jlgOFaQHvZVE/Ca0wpvZOJN+dQ9K7F3DIeim3915qnqyaexjYWV/P/MN/dk0dFV2kJg5KHpKep+DeS0yAQ6rB/ZvFwctJfq4zMB4MmaRLK8gloEHtJVmJTiY7mg8nRAHdKiX2tBJE7E83uSZmtyge2Kht/0RigRTXLpONixge8LhxeItMxh1VIXw==" Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 06 16:18:38 volumio volumio[4021]: info: CoreCommandRouter::volumioGetState Oct 06 16:18:38 volumio volumio[4021]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:38 volumio sudo[4181]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:38 volumio sudo[4185]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 06 16:18:38 volumio sudo[4185]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:38 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 06 16:18:38 volumio sudo[4178]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:39 volumio mpd[4121]: Oct 06 16:18 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 06 16:18:39 volumio go-librespot[4161]: time="2024-10-06T16:18:39+02:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:4070 (error: dial tcp 34.158.1.133:4070: connect: connection refused), retrying with a different AP" Oct 06 16:18:39 volumio systemd[1]: Started Music Player Daemon. Oct 06 16:18:39 volumio sudo[4110]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:39 volumio sudo[4099]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:39 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 06 16:18:39 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 06 16:18:39 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 06 16:18:39 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 06 16:18:39 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 06 16:18:39 volumio go-librespot[4161]: time="2024-10-06T16:18:39+02:00" level=info msg="connected to ap-gew4.spotify.com:443" Oct 06 16:18:39 volumio sudo[4185]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:39 volumio sudo[4181]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:39 volumio go-librespot[4161]: time="2024-10-06T16:18:39+02:00" level=debug msg="completed keyexchange" Oct 06 16:18:39 volumio volumio[4021]: info: CoreCommandRouter::volumioGetVisibleSources Oct 06 16:18:39 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:18:39 volumio volumio[4021]: info: CoreCommandRouter::volumioGetState Oct 06 16:18:39 volumio volumio[4021]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:39 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 06 16:18:39 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 06 16:18:39 volumio volumio[4021]: info: Received Get System Info Oct 06 16:18:39 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 06 16:18:39 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 06 16:18:39 volumio volumio[4021]: info: Discovery: Getting this device information Oct 06 16:18:39 volumio volumio[4021]: info: CoreCommandRouter::volumioGetState Oct 06 16:18:39 volumio volumio[4021]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:39 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 06 16:18:39 volumio volumio[4021]: info: CoreCommandRouter::volumioGetState Oct 06 16:18:39 volumio volumio[4021]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:39 volumio volumio[4021]: info: Listing playlists Oct 06 16:18:39 volumio volumio[4021]: info: CoreCommandRouter::volumioGetQueue Oct 06 16:18:39 volumio volumio[4021]: info: CoreStateMachine::getQueue Oct 06 16:18:39 volumio volumio[4021]: info: CorePlayQueue::getQueue Oct 06 16:18:39 volumio volumio[4021]: info: Shairport-Sync Started Oct 06 16:18:39 volumio volumio[4021]: Error adding Membership: Error: addMembership EINVAL Oct 06 16:18:39 volumio volumio[4021]: info: Shairport-Sync Started Oct 06 16:18:39 volumio volumio[4021]: info: Completed starting Core Plugins Oct 06 16:18:39 volumio volumio[4021]: info: ------------------------------------------- Oct 06 16:18:39 volumio volumio[4021]: info: ----- MyVolumio plugins startup ---- Oct 06 16:18:39 volumio volumio[4021]: info: ------------------------------------------- Oct 06 16:18:39 volumio volumio[4021]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 06 16:18:39 volumio volumio[4021]: info: Shairport-Sync Started Oct 06 16:18:39 volumio volumio[4021]: error: MPD error: The expression evaluated to a falsy value: Oct 06 16:18:39 volumio volumio[4021]: assert.ok(self.idling) Oct 06 16:18:39 volumio volumio[4021]: error: The expression evaluated to a falsy value: Oct 06 16:18:39 volumio volumio[4021]: assert.ok(self.idling) Oct 06 16:18:39 volumio volumio[4021]: info: MPD running with PID4121 Oct 06 16:18:39 volumio volumio[4021]: ,establishing connection Oct 06 16:18:39 volumio volumio[4021]: error: updateQueue error: null Oct 06 16:18:39 volumio volumio[4021]: error: updateQueue error: null Oct 06 16:18:39 volumio volumio[4021]: SPOTIFY: User informations: {"display_name":"gronk","external_urls":{"spotify":"https://open.spotify.com/user/gronk"},"href":"https://api.spotify.com/v1/users/gronk","id":"gronk","images":[],"type":"user","uri":"spotify:user:gronk","followers":{"href":null,"total":3},"country":"SE","product":"premium","explicit_content":{"filter_enabled":false,"filter_locked":false},"email":"maglar@me.com"} Oct 06 16:18:39 volumio volumio[4021]: info: Spotify Successfully logged in Oct 06 16:18:39 volumio volumio[4021]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:18:39 volumio volumio[4021]: info: [1728224319296] CoreMusicLibrary::Adding element Spotify Oct 06 16:18:39 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:18:39 volumio volumio[4021]: Cannot find translation for source Bandcamp Discover Oct 06 16:18:39 volumio volumio[4021]: Cannot find translation for source SoundCloud Oct 06 16:18:39 volumio volumio[4021]: Cannot find translation for source Spotify Oct 06 16:18:39 volumio go-librespot[4161]: time="2024-10-06T16:18:39+02:00" level=debug msg="completed challenge" Oct 06 16:18:39 volumio go-librespot[4161]: time="2024-10-06T16:18:39+02:00" level=debug msg="authenticated as gronk" Oct 06 16:18:39 volumio go-librespot[4161]: time="2024-10-06T16:18:39+02:00" level=debug msg="authenticated as gronk" Oct 06 16:18:39 volumio go-librespot[4161]: time="2024-10-06T16:18:39+02:00" level=debug msg="dealer connection opened" Oct 06 16:18:39 volumio go-librespot[4161]: time="2024-10-06T16:18:39+02:00" level=debug msg="initializing zeroconf session, username: gronk" Oct 06 16:18:39 volumio go-librespot[4161]: time="2024-10-06T16:18:39+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 06 16:18:39 volumio go-librespot[4161]: time="2024-10-06T16:18:39+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 06 16:18:39 volumio go-librespot[4161]: time="2024-10-06T16:18:39+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 06 16:18:39 volumio go-librespot[4161]: time="2024-10-06T16:18:39+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 06 16:18:39 volumio go-librespot[4161]: time="2024-10-06T16:18:39+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 493" Oct 06 16:18:39 volumio volumio[4021]: info: Cannot mount NAS Diskstation at system boot, trial number 2 ,retrying in 5 seconds Oct 06 16:18:39 volumio go-librespot[4161]: time="2024-10-06T16:18:39+02:00" level=debug msg="autoplay enabled: false" Oct 06 16:18:39 volumio go-librespot[4161]: time="2024-10-06T16:18:39+02:00" level=debug msg="received connection id: NWE2MzMxMGUtYmE1OS00ZjkzLTlmOTMtNWZkZmE4MTBkMDAyK2RlYWxlcit0Y3A6Ly8wYWNhNTg4Yy5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArREMwQjg5NzUxMjkyQzU3NjI2NjdDM0RFNjAwQTkxRkQxODM2NTIyQkZEMEMwQzhGNUVCRDY3ODY3MUU5ODc0Qg==" Oct 06 16:18:41 volumio volumio[4021]: info: go-librespot daemon successfully initialized Oct 06 16:18:44 volumio volumio[4021]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 06 16:18:44 volumio volumio[4021]: info: Initializing connection to go-librespot Websocket Oct 06 16:18:44 volumio go-librespot[4161]: time="2024-10-06T16:18:44+02:00" level=debug msg="new websocket client" Oct 06 16:18:44 volumio volumio[4021]: info: Connection to go-librespot Websocket established Oct 06 16:18:44 volumio volumio[4021]: info: Cannot mount NAS Diskstation at system boot, trial number 3 ,retrying in 5 seconds Oct 06 16:18:44 volumio sudo[4197]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 06 16:18:44 volumio sudo[4197]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:44 volumio sudo[4197]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:44 volumio sudo[4200]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 06 16:18:44 volumio sudo[4200]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:44 volumio sudo[4200]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:44 volumio sudo[4203]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 06 16:18:44 volumio sudo[4203]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:45 volumio systemd[1]: Started UPnP Renderer front-end to MPD. Oct 06 16:18:45 volumio sudo[4203]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:45 volumio volumio[4021]: info: Upmpdcli Daemon Started Oct 06 16:18:45 volumio volumio[4205]: writing RSA key Oct 06 16:18:45 volumio go-librespot[4161]: time="2024-10-06T16:18:45+02:00" level=debug msg="put connect state because NEW_DEVICE" Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 06 16:18:47 volumio volumio[4021]: info: Adding plugin bluetooth to MyMusic Plugins Oct 06 16:18:47 volumio volumio[4021]: info: Adding plugin multiroom to MyMusic Plugins Oct 06 16:18:47 volumio volumio[4021]: info: Adding plugin metavolumio to MyMusic Plugins Oct 06 16:18:47 volumio volumio[4021]: info: Adding plugin cd_controller to MyMusic Plugins Oct 06 16:18:47 volumio volumio[4021]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 06 16:18:47 volumio volumio[4021]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 06 16:18:47 volumio volumio[4021]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 06 16:18:48 volumio volumio[4021]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 06 16:18:48 volumio volumio[4021]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 06 16:18:48 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:18:48 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:18:48 volumio volumio[4021]: info: Starting MyVolumio Remote Streaming Endpoints Oct 06 16:18:48 volumio volumio[4021]: info: MyVolumio login type: Token Oct 06 16:18:48 volumio volumio[4021]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 06 16:18:48 volumio volumio[4021]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 06 16:18:48 volumio volumio[4021]: info: Starting Streaming Service Transparent Proxy Oct 06 16:18:48 volumio volumio[4021]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 06 16:18:48 volumio volumio[4021]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 06 16:18:48 volumio volumio[4021]: info: Streaming services startup Oct 06 16:18:48 volumio volumio[4021]: info: Starting Streaming Daemon Oct 06 16:18:48 volumio sudo[4249]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 06 16:18:48 volumio sudo[4249]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:48 volumio sudo[4249]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:48 volumio volumio[4021]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 06 16:18:48 volumio volumio[4021]: info: Getting Spotify volume Oct 06 16:18:48 volumio volumio[4021]: error: Cannot start Volumio Streaming Daemon Oct 06 16:18:48 volumio volumio[4021]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 06 16:18:48 volumio volumio[4021]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 06 16:18:48 volumio volumio[4021]: info: Spotify volume: 100 Oct 06 16:18:48 volumio volumio[4021]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 06 16:18:49 volumio volumio[4021]: info: CoreCommandRouter::volumioGetState Oct 06 16:18:49 volumio volumio[4021]: info: CorePlayQueue::getTrack 0 Oct 06 16:18:49 volumio volumio[4021]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 06 16:18:49 volumio volumio[4021]: STREAMING PROXY: Starting server on port 3245 Oct 06 16:18:49 volumio volumio[4021]: Node JS runtime: 14 Oct 06 16:18:49 volumio volumio[4021]: info: Cannot mount NAS Diskstation at system boot, trial number 4 ,retrying in 5 seconds Oct 06 16:18:49 volumio volumio[4021]: info: MyVolumio token set successfully Oct 06 16:18:49 volumio volumio[4021]: info: MYVOLUMIO: Adding device Oct 06 16:18:49 volumio volumio[4021]: info: MYVOLUMIO: Evaluating Server Oct 06 16:18:50 volumio volumio[4021]: info: MyVolumio status changed Oct 06 16:18:50 volumio volumio[4021]: info: Streaming services startup Oct 06 16:18:50 volumio volumio[4021]: info: Starting Streaming Daemon Oct 06 16:18:50 volumio volumio[4021]: info: Removing browser output: myVolumio user plan is not superstar Oct 06 16:18:50 volumio volumio[4021]: info: Removing audio output: Oct 06 16:18:50 volumio volumio[4021]: info: Stoppping Tunnel 1 Oct 06 16:18:50 volumio sudo[4275]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 06 16:18:50 volumio sudo[4275]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:50 volumio sudo[4275]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:50 volumio volumio[4021]: error: Cannot start Volumio Streaming Daemon Oct 06 16:18:50 volumio volumio[4021]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 06 16:18:50 volumio volumio[4021]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 06 16:18:50 volumio sudo[4278]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 06 16:18:50 volumio sudo[4278]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:50 volumio sudo[4278]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:50 volumio volumio[4021]: info: Remote SSH Stopped Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 06 16:18:50 volumio volumio[4021]: info: Retrieving Cloud Streaming UI Oct 06 16:18:50 volumio volumio[4021]: info: Getting Tidal Cloud Configuration Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 06 16:18:50 volumio volumio[4021]: info: Getting Qobuz Cloud Configuration Oct 06 16:18:50 volumio volumio[4021]: info: Asking plugin for UI Config Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 06 16:18:50 volumio volumio[4021]: info: Getting Spotify Cloud Configuration Oct 06 16:18:50 volumio volumio[4021]: info: Asking plugin for UI Config Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 06 16:18:50 volumio volumio[4021]: info: Saving Spotify Acccount Oct 06 16:18:50 volumio volumio[4021]: info: Got Tidal Cloud Configuration Oct 06 16:18:50 volumio volumio[4021]: info: Got it Oct 06 16:18:50 volumio volumio[4021]: info: Got it Oct 06 16:18:50 volumio volumio[4021]: error: Could not retrieve Spotify Config from plugin Spotify: no section found Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 06 16:18:50 volumio volumio[4021]: error: Error retrieving Highresaudio conf: TypeError: Cannot read property 'onSave' of undefined Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: albumart , getConfigParam Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::volumioGetBrowseSources Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::volumioGetBrowseSources Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::volumioGetBrowseSources Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 06 16:18:50 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares Oct 06 16:18:54 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: networkfs , deleteShare Oct 06 16:18:54 volumio volumio[4021]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 06 16:18:54 volumio sudo[4284]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/umount /mnt/NAS/Diskstation Oct 06 16:18:54 volumio sudo[4284]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:54 volumio systemd[1]: mnt-NAS-Diskstation.mount: Succeeded. Oct 06 16:18:54 volumio sudo[4288]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto 192.168.2.64:/volume1/Music /mnt/NAS/Diskstation Oct 06 16:18:54 volumio sudo[4288]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:54 volumio sudo[4284]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:54 volumio volumio[4021]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 06 16:18:54 volumio volumio[4021]: Error: EBUSY: resource busy or locked, rmdir '/mnt/NAS/Diskstation' Oct 06 16:18:54 volumio volumio[4021]: at Object.rmdirSync (fs.js:890:10) Oct 06 16:18:54 volumio volumio[4021]: at /volumio/node_modules/linux-mountutils/mountutils.js:178:12 Oct 06 16:18:54 volumio volumio[4021]: at ChildProcess.exithandler (child_process.js:299:7) Oct 06 16:18:54 volumio volumio[4021]: at ChildProcess.emit (events.js:315:20) Oct 06 16:18:54 volumio volumio[4021]: at maybeClose (internal/child_process.js:1048:16) Oct 06 16:18:54 volumio volumio[4021]: at Process.ChildProcess._handle.onexit (internal/child_process.js:288:5) { Oct 06 16:18:54 volumio volumio[4021]: errno: -16, Oct 06 16:18:54 volumio volumio[4021]: syscall: 'rmdir', Oct 06 16:18:54 volumio volumio[4021]: code: 'EBUSY', Oct 06 16:18:54 volumio volumio[4021]: path: '/mnt/NAS/Diskstation' Oct 06 16:18:54 volumio volumio[4021]: } Oct 06 16:18:54 volumio volumio[4021]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 06 16:18:54 volumio sudo[4288]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:55 volumio sudo[4304]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-06 16:17 Oct 06 16:18:55 volumio sudo[4304]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:55 volumio sudo[4304]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:55 volumio volumio-remote-updater[1339]: [2024-10-06 16:18:55] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 06 16:18:55 volumio volumio-remote-updater[1339]: [2024-10-06 16:18:55] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 06 16:18:55 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 06 16:18:55 volumio go-librespot[4161]: time="2024-10-06T16:18:55+02:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF" Oct 06 16:18:55 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 06 16:18:55 volumio systemd[1]: Started dynamicswap service. Oct 06 16:18:55 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 06 16:18:55 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 06 16:18:55 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 3. Oct 06 16:18:55 volumio systemd[1]: Started dynamicswap service. Oct 06 16:18:55 volumio systemd[1]: Stopped Volumio Backend Module. Oct 06 16:18:55 volumio systemd[1]: Started Volumio Backend Module. Oct 06 16:18:55 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 06 16:18:56 volumio volumio[4318]: info: ------------------------------------------- Oct 06 16:18:56 volumio volumio[4318]: info: ----- Volumio3 ---- Oct 06 16:18:56 volumio volumio[4318]: info: ------------------------------------------- Oct 06 16:18:56 volumio volumio[4318]: info: ----- System startup ---- Oct 06 16:18:56 volumio volumio[4318]: info: ------------------------------------------- Oct 06 16:18:57 volumio volumio[4318]: info: MYVOLUMIO Environment detected Oct 06 16:18:57 volumio volumio[4318]: info: Plugin folders cleanup Oct 06 16:18:57 volumio volumio[4318]: info: Scanning into folder /volumio/app/plugins/ Oct 06 16:18:57 volumio volumio[4318]: info: Scanning category audio_interface Oct 06 16:18:57 volumio volumio[4318]: info: Scanning category miscellanea Oct 06 16:18:57 volumio volumio[4318]: info: Scanning category music_service Oct 06 16:18:57 volumio volumio[4318]: info: Scanning category plugins.json Oct 06 16:18:57 volumio volumio[4318]: info: Scanning category system_controller Oct 06 16:18:57 volumio volumio[4318]: info: Scanning category user_interface Oct 06 16:18:57 volumio volumio[4318]: info: Scanning into folder /data/plugins/ Oct 06 16:18:57 volumio volumio[4318]: info: Scanning category music_service Oct 06 16:18:57 volumio volumio[4318]: info: Plugin folders cleanup completed Oct 06 16:18:57 volumio volumio[4318]: info: ------------------------------------------- Oct 06 16:18:57 volumio volumio[4318]: info: ----- Core plugins startup ---- Oct 06 16:18:57 volumio volumio[4318]: info: ------------------------------------------- Oct 06 16:18:57 volumio volumio[4318]: info: Loading plugins from folder /volumio/app/plugins/ Oct 06 16:18:57 volumio volumio[4318]: info: Adding plugin upnp to MyMusic Plugins Oct 06 16:18:57 volumio volumio[4318]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 06 16:18:57 volumio volumio[4318]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 06 16:18:57 volumio volumio[4318]: info: Loading plugins from folder /data/plugins/ Oct 06 16:18:57 volumio volumio[4318]: info: Loading plugin "system"... Oct 06 16:18:57 volumio volumio[4318]: info: Loading plugin "appearance"... Oct 06 16:18:57 volumio volumio[4318]: info: Loading plugin "network"... Oct 06 16:18:57 volumio volumio[4318]: info: Refreshing Cached IP Addresses Oct 06 16:18:57 volumio sudo[4344]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 06 16:18:57 volumio sudo[4344]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:57 volumio sudo[4344]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:57 volumio sudo[4346]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 06 16:18:57 volumio sudo[4346]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:57 volumio volumio[4318]: info: Loading plugin "services"... Oct 06 16:18:57 volumio volumio[4318]: info: Loading plugin "alsa_controller"... Oct 06 16:18:57 volumio sudo[4346]: pam_unix(sudo:session): session closed for user root Oct 06 16:18:57 volumio sudo[4350]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 06 16:18:57 volumio sudo[4350]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:18:57 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 06 16:18:57 volumio volumio[4318]: info: Loading plugin "wizard"... Oct 06 16:18:57 volumio volumio[4318]: info: Loading plugin "networkfs"... Oct 06 16:18:58 volumio volumio[4318]: info: Cannot mount NAS Diskstation at system boot, trial number 1 ,retrying in 5 seconds Oct 06 16:18:58 volumio volumio[4318]: info: Starting Udev Watcher for removable devices Oct 06 16:18:58 volumio volumio[4318]: info: Ignoring mount for partition: boot Oct 06 16:18:58 volumio volumio[4318]: info: Ignoring mount for partition: volumio Oct 06 16:18:58 volumio volumio[4318]: info: Ignoring mount for partition: volumio_data Oct 06 16:18:58 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 06 16:18:58 volumio volumio[4318]: info: Loading plugin "volumio_command_line_client"... Oct 06 16:18:58 volumio volumio[4318]: info: Loading plugin "upnp"... Oct 06 16:18:58 volumio volumio[4318]: info: [1728224338042] Starting Upmpd Daemon Oct 06 16:18:58 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 06 16:18:58 volumio volumio[4318]: info: Loading plugin "my_music"... Oct 06 16:18:58 volumio volumio[4318]: info: Loading plugin "mpd"... Oct 06 16:18:58 volumio volumio[4318]: info: Loading plugin "upnp_browser"... Oct 06 16:18:58 volumio volumio[4318]: info: Loading plugin "alarm-clock"... Oct 06 16:18:58 volumio volumio[4318]: info: Loading plugin "airplay_emulation"... Oct 06 16:18:58 volumio volumio[4318]: info: Starting Shairport Sync Oct 06 16:18:58 volumio volumio[4318]: info: Loading plugin "last_100"... Oct 06 16:18:58 volumio volumio[4318]: info: Loading plugin "webradio"... Oct 06 16:18:58 volumio volumio[4318]: info: Loading plugin "i2s_dacs"... Oct 06 16:18:58 volumio volumio[4318]: info: Loading plugin "volumiodiscovery"... Oct 06 16:18:58 volumio volumio[4318]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 06 16:18:58 volumio volumio[4318]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 06 16:18:58 volumio node[4318]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 06 16:18:58 volumio volumio[4318]: *** WARNING *** For more information see Oct 06 16:18:58 volumio volumio[4318]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 06 16:18:58 volumio volumio[4318]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 06 16:18:58 volumio volumio[4318]: *** WARNING *** For more information see Oct 06 16:18:58 volumio node[4318]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 06 16:18:58 volumio node[4318]: *** WARNING *** For more information see Oct 06 16:18:58 volumio node[4318]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 06 16:18:58 volumio node[4318]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 06 16:18:58 volumio node[4318]: *** WARNING *** For more information see Oct 06 16:18:58 volumio volumio[4318]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 06 16:18:58 volumio volumio[4318]: info: Discovery: Started advertising with name: Volumio Oct 06 16:18:58 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 06 16:18:58 volumio volumio[4318]: info: Loading plugin "bandcamp"... Oct 06 16:18:59 volumio volumio[4318]: info: Loading plugin "soundcloud"... Oct 06 16:18:59 volumio volumio[4318]: info: Loading plugin "spop"... Oct 06 16:19:00 volumio volumio[4318]: info: Loading plugin "outputs"... Oct 06 16:19:00 volumio volumio[4318]: info: Loading plugin "albumart"... Oct 06 16:19:00 volumio volumio[4318]: info: Plugin example_plugin is not enabled Oct 06 16:19:00 volumio volumio[4318]: info: Loading plugin "inputs"... Oct 06 16:19:00 volumio volumio[4318]: info: Loading plugin "updater_comm"... Oct 06 16:19:00 volumio volumio[4318]: info: Plugin mpdemulation is not enabled Oct 06 16:19:00 volumio volumio[4318]: info: Loading plugin "rest_api"... Oct 06 16:19:00 volumio volumio[4318]: info: Loading plugin "websocket"... Oct 06 16:19:00 volumio volumio[4318]: info: Starting Socket.io Server version 2.3.0 Oct 06 16:19:00 volumio volumio[4318]: info: Loading i18n strings for locale sv Oct 06 16:19:00 volumio volumio[4318]: Updating browse sources language Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 06 16:19:00 volumio volumio[4318]: Forking 3 albumart workers Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::initPlayerControls Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 06 16:19:00 volumio volumio[4318]: Express server listening on port 3000 Oct 06 16:19:00 volumio volumio[4318]: [Metrics] WebUI: 3s 807.39ms Oct 06 16:19:00 volumio volumio[4318]: info: CoreStateMachine::resetVolumioState Oct 06 16:19:00 volumio volumio[4318]: info: CoreStateMachine::getcurrentVolume Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::volumioRetrievevolume Oct 06 16:19:00 volumio volumio[4318]: info: CoreStateMachine::pushState Oct 06 16:19:00 volumio volumio[4318]: info: CorePlayQueue::getTrack 0 Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::volumioPushState Oct 06 16:19:00 volumio volumio[4318]: verbose: New Socket.io Connection to 192.168.2.53 from 192.168.2.42 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 1 Oct 06 16:19:00 volumio volumio[4318]: verbose: New Socket.io Connection to 192.168.2.53 from 192.168.2.42 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 2 Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:19:00 volumio volumio[4318]: info: Reloading queue from file Oct 06 16:19:00 volumio volumio[4318]: info: CoreStateMachine::setRepeat null single undefined Oct 06 16:19:00 volumio volumio[4318]: info: CoreStateMachine::pushState Oct 06 16:19:00 volumio volumio[4318]: info: CorePlayQueue::getTrack 0 Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::volumioPushState Oct 06 16:19:00 volumio volumio[4318]: info: CoreStateMachine::setRandom null Oct 06 16:19:00 volumio volumio[4318]: info: CoreStateMachine::pushState Oct 06 16:19:00 volumio volumio[4318]: info: CorePlayQueue::getTrack 0 Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::volumioPushState Oct 06 16:19:00 volumio volumio[4318]: info: Setting Device type: Raspberry PI Oct 06 16:19:00 volumio volumio[4318]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 06 16:19:00 volumio volumio[4318]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03115 Oct 06 16:19:00 volumio volumio[4318]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 06 16:19:00 volumio volumio[4318]: info: Completed loading Core Plugins Oct 06 16:19:00 volumio volumio[4318]: info: Preparing to generate the ALSA configuration file Oct 06 16:19:00 volumio volumio[4318]: info: Asound.conf file unchanged, so no further update is needed Oct 06 16:19:00 volumio volumio[4318]: info: Output device has changed, restarting MPD Oct 06 16:19:00 volumio sudo[4394]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 06 16:19:00 volumio sudo[4394]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:19:00 volumio volumio[4318]: info: Output device has changed, restarting Shairport Sync Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:19:00 volumio sudo[4394]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:00 volumio volumio-remote-updater[1339]: [2024-10-06 16:19:00] [connect] Successful connection Oct 06 16:19:00 volumio sudo[4395]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 06 16:19:00 volumio sudo[4395]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:19:00 volumio systemd[1]: Stopping Music Player Daemon... Oct 06 16:19:00 volumio volumio[4318]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 06 16:19:00 volumio volumio[4318]: info: ___________ START PLUGINS ___________ Oct 06 16:19:00 volumio systemd[1]: mpd.service: Succeeded. Oct 06 16:19:00 volumio systemd[1]: Stopped Music Player Daemon. Oct 06 16:19:00 volumio volumio[4318]: info: ControllerMpd::onStart: Initializing MPD Oct 06 16:19:00 volumio volumio[4318]: info: Creating MPD Configuration file Oct 06 16:19:00 volumio systemd[1]: Starting Music Player Daemon... Oct 06 16:19:00 volumio sudo[4404]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 06 16:19:00 volumio sudo[4404]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:19:00 volumio volumio[4318]: info: [1728224340850] CoreMusicLibrary::Adding element Mediaservrar Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:19:00 volumio sudo[4404]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:00 volumio sudo[4406]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 06 16:19:00 volumio sudo[4406]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:19:00 volumio sudo[4401]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 06 16:19:00 volumio sudo[4401]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:19:00 volumio sudo[4401]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:19:00 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Oct 06 16:19:00 volumio systemd[1]: mpd.service: Succeeded. Oct 06 16:19:00 volumio systemd[1]: Stopped Music Player Daemon. Oct 06 16:19:00 volumio volumio[4318]: Starting albumart workers Oct 06 16:19:00 volumio volumio[4318]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:00 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:19:00 volumio systemd[1]: Starting Music Player Daemon... Oct 06 16:19:01 volumio volumio[4318]: Starting albumart workers Oct 06 16:19:01 volumio volumio[4318]: Starting albumart workers Oct 06 16:19:01 volumio sudo[4413]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 06 16:19:01 volumio sudo[4413]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:19:01 volumio sudo[4413]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:01 volumio volumio[4318]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:19:01 volumio volumio[4318]: info: [1728224341095] CoreMusicLibrary::Adding element Last_100 Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:19:01 volumio volumio[4318]: info: [1728224341100] CoreMusicLibrary::Adding element Webradio Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 06 16:19:01 volumio volumio[4318]: info: Initializing BBC Radios Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:19:01 volumio volumio[4318]: info: [1728224341382] CoreMusicLibrary::Adding element Bandcamp Discover Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:19:01 volumio volumio[4318]: Cannot find translation for source Bandcamp Discover Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:19:01 volumio volumio[4318]: info: [1728224341402] CoreMusicLibrary::Adding element SoundCloud Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:19:01 volumio volumio[4318]: Cannot find translation for source Bandcamp Discover Oct 06 16:19:01 volumio volumio[4318]: Cannot find translation for source SoundCloud Oct 06 16:19:01 volumio volumio[4318]: info: Creating Spotify config file Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: Volumio Calling Home Oct 06 16:19:01 volumio sudo[4350]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:01 volumio volumio[4318]: info: Discovery: adding bdec9109-a559-4acf-9692-dc69c4c6c743 Oct 06 16:19:01 volumio volumio[4318]: info: Discovery: Found device Volumio Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::volumioGetState Oct 06 16:19:01 volumio volumio[4318]: info: CorePlayQueue::getTrack 0 Oct 06 16:19:01 volumio volumio[4318]: info: MPD Permissions set Oct 06 16:19:01 volumio volumio[4318]: info: MPD Permissions set Oct 06 16:19:01 volumio volumio-remote-updater[1339]: [2024-10-06 16:19:01] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1728224340 101 Oct 06 16:19:01 volumio volumio[4318]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 3 Oct 06 16:19:01 volumio volumio[4318]: info: Spotify config file written Oct 06 16:19:01 volumio sudo[4457]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Oct 06 16:19:01 volumio sudo[4457]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:19:01 volumio systemd[1]: Stopping go-librespot Daemon... Oct 06 16:19:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Oct 06 16:19:01 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Oct 06 16:19:01 volumio systemd[1]: Stopped go-librespot Daemon. Oct 06 16:19:01 volumio volumio[4318]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:19:01 volumio systemd[1]: Started go-librespot Daemon. Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio go-librespot[4459]: Librespot-go daemon starting... Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio sudo[4457]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:01 volumio go-librespot[4459]: time="2024-10-06T16:19:01+02:00" level=info msg="generated new device id: 4bd2caa315bc842d1b28e599af3c97c60788ce82" Oct 06 16:19:01 volumio go-librespot[4459]: time="2024-10-06T16:19:01+02:00" level=debug msg="stored credentials found for gronk" Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 06 16:19:01 volumio volumio[4318]: info: No need to fix Spotify hosts Oct 06 16:19:01 volumio volumio[4318]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 06 16:19:01 volumio volumio[4318]: SPOTIFY: BQCWyeen0JfBZXGbx4SFKQRUp2VgH67TFqw56cuNecbB2ss_qTOBpjzffDQcKME40o6rgxwQHLoBKU5zzHqSXIXyXAIScRqDvRU8xvPgsoz3W13MaK2uXiAQ70wQv7PqDx9QNveXbuoPiIaywJIOLHEgB5c92kMwQuaWCe9LGRm7eS0mXRP-lW10MJnogMtJ5MC-8HwHj9I3-2IXdjGvuCr_sW_NQASZHNaFPvNuLhJjKjUw01P5 Oct 06 16:19:01 volumio volumio[4318]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Oct 06 16:19:01 volumio volumio[4318]: info: New Spotify access token = BQCWyeen0JfBZXGbx4SFKQRUp2VgH67TFqw56cuNecbB2ss_qTOBpjzffDQcKME40o6rgxwQHLoBKU5zzHqSXIXyXAIScRqDvRU8xvPgsoz3W13MaK2uXiAQ70wQv7PqDx9QNveXbuoPiIaywJIOLHEgB5c92kMwQuaWCe9LGRm7eS0mXRP-lW10MJnogMtJ5MC-8HwHj9I3-2IXdjGvuCr_sW_NQASZHNaFPvNuLhJjKjUw01P5 Oct 06 16:19:01 volumio volumio[4318]: info: Spotify credentials grant success - running version from March 24, 2019 Oct 06 16:19:02 volumio volumio[4318]: info: Starting Shairport Sync Oct 06 16:19:02 volumio volumio[4318]: info: Starting Shairport Sync Oct 06 16:19:02 volumio sudo[4478]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 06 16:19:02 volumio sudo[4478]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:19:02 volumio go-librespot[4459]: time="2024-10-06T16:19:02+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-gae2.spotify.com:80]" Oct 06 16:19:02 volumio go-librespot[4459]: time="2024-10-06T16:19:02+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Oct 06 16:19:02 volumio go-librespot[4459]: time="2024-10-06T16:19:02+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Oct 06 16:19:02 volumio volumio[4318]: info: Starting Shairport Sync Oct 06 16:19:02 volumio go-librespot[4459]: time="2024-10-06T16:19:02+02:00" level=debug msg="zeroconf server listening on port 45257" Oct 06 16:19:02 volumio sudo[4481]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 06 16:19:02 volumio sudo[4481]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:19:02 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 06 16:19:02 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 06 16:19:02 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 06 16:19:02 volumio sudo[4484]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 06 16:19:02 volumio sudo[4484]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:19:02 volumio go-librespot[4459]: time="2024-10-06T16:19:02+02:00" level=debug msg="obtained new client token: AAAziitLqH68TsdadOlcI/nGc6qslVVKBXzpN0a1gLKzxmc1AnIXYDKccxf2XsxxRTlr1aCAs0H5EJ/vO3heb9WbKzhqWJ3RwQqU6qDL5K7Q40wy/blGNNkDokEdgmuw3XMQU/zIi/XywudL447RI2b2OsHYPeQ10EDeEneBDgxb+JrDKnG27UOmFrdwcPruQimThnznGUjZTYbahboKlY+ahjMbCAeljn0p8tSZVBClgbL7Kf0HoY4eFUM=" Oct 06 16:19:02 volumio go-librespot[4459]: time="2024-10-06T16:19:02+02:00" level=info msg="connected to ap-gew4.spotify.com:4070" Oct 06 16:19:02 volumio mpd[4418]: Oct 06 16:19 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 06 16:19:02 volumio volumio[4318]: info: CoreCommandRouter::volumioGetState Oct 06 16:19:02 volumio volumio[4318]: info: CorePlayQueue::getTrack 0 Oct 06 16:19:02 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 06 16:19:02 volumio systemd[1]: Started Music Player Daemon. Oct 06 16:19:02 volumio sudo[4406]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:02 volumio go-librespot[4459]: time="2024-10-06T16:19:02+02:00" level=debug msg="completed keyexchange" Oct 06 16:19:02 volumio sudo[4395]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:02 volumio sudo[4478]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:02 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 06 16:19:02 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Oct 06 16:19:02 volumio systemd[1]: shairport-sync.service: Succeeded. Oct 06 16:19:02 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 06 16:19:02 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 06 16:19:02 volumio sudo[4481]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:02 volumio sudo[4484]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:02 volumio volumio[4318]: info: Completed starting Core Plugins Oct 06 16:19:02 volumio volumio[4318]: info: ------------------------------------------- Oct 06 16:19:02 volumio volumio[4318]: info: ----- MyVolumio plugins startup ---- Oct 06 16:19:02 volumio volumio[4318]: info: ------------------------------------------- Oct 06 16:19:02 volumio volumio[4318]: info: [MyVolumio PluginManager] Fetching plans data.... Oct 06 16:19:02 volumio volumio[4318]: info: Shairport-Sync Started Oct 06 16:19:02 volumio volumio[4318]: Error adding Membership: Error: addMembership EINVAL Oct 06 16:19:02 volumio volumio[4318]: info: Shairport-Sync Started Oct 06 16:19:02 volumio volumio[4318]: info: Shairport-Sync Started Oct 06 16:19:02 volumio volumio[4318]: error: MPD error: The expression evaluated to a falsy value: Oct 06 16:19:02 volumio volumio[4318]: assert.ok(self.idling) Oct 06 16:19:02 volumio volumio[4318]: error: The expression evaluated to a falsy value: Oct 06 16:19:02 volumio volumio[4318]: assert.ok(self.idling) Oct 06 16:19:02 volumio volumio[4318]: info: MPD running with PID4418 Oct 06 16:19:02 volumio volumio[4318]: ,establishing connection Oct 06 16:19:02 volumio volumio[4318]: error: MPD error: The expression evaluated to a falsy value: Oct 06 16:19:02 volumio volumio[4318]: assert.ok(self.idling) Oct 06 16:19:02 volumio volumio[4318]: error: The expression evaluated to a falsy value: Oct 06 16:19:02 volumio volumio[4318]: assert.ok(self.idling) Oct 06 16:19:02 volumio volumio[4318]: error: updateQueue error: null Oct 06 16:19:02 volumio volumio[4318]: SPOTIFY: User informations: {"display_name":"gronk","external_urls":{"spotify":"https://open.spotify.com/user/gronk"},"href":"https://api.spotify.com/v1/users/gronk","id":"gronk","images":[],"type":"user","uri":"spotify:user:gronk","followers":{"href":null,"total":3},"country":"SE","product":"premium","explicit_content":{"filter_enabled":false,"filter_locked":false},"email":"maglar@me.com"} Oct 06 16:19:02 volumio volumio[4318]: info: Spotify Successfully logged in Oct 06 16:19:02 volumio volumio[4318]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 06 16:19:02 volumio volumio[4318]: info: [1728224342429] CoreMusicLibrary::Adding element Spotify Oct 06 16:19:02 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:19:02 volumio volumio[4318]: Cannot find translation for source Bandcamp Discover Oct 06 16:19:02 volumio volumio[4318]: Cannot find translation for source SoundCloud Oct 06 16:19:02 volumio volumio[4318]: Cannot find translation for source Spotify Oct 06 16:19:02 volumio go-librespot[4459]: time="2024-10-06T16:19:02+02:00" level=debug msg="completed challenge" Oct 06 16:19:02 volumio go-librespot[4459]: time="2024-10-06T16:19:02+02:00" level=debug msg="authenticated as gronk" Oct 06 16:19:03 volumio volumio[4318]: info: Cannot mount NAS Diskstation at system boot, trial number 2 ,retrying in 5 seconds Oct 06 16:19:03 volumio volumio[4318]: verbose: New Socket.io Connection to 192.168.2.53 from 192.168.2.42 UA: Mozilla/5.0 (iPhone; CPU iPhone OS 17_6_1 like Mac OS X) AppleWebKit/605.1.15 (KHTML, like Gecko) Mobile/15E148 Engine version: 3 Transport: polling Total Clients: 5 Oct 06 16:19:03 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 06 16:19:03 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats Oct 06 16:19:03 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 06 16:19:03 volumio volumio[4318]: info: CoreCommandRouter::volumioGetVisibleSources Oct 06 16:19:03 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 06 16:19:03 volumio volumio[4318]: info: CoreCommandRouter::volumioGetState Oct 06 16:19:03 volumio volumio[4318]: info: CorePlayQueue::getTrack 0 Oct 06 16:19:03 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 06 16:19:03 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 06 16:19:03 volumio volumio[4318]: info: Received Get System Info Oct 06 16:19:03 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 06 16:19:03 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 06 16:19:03 volumio volumio[4318]: info: Discovery: Getting this device information Oct 06 16:19:03 volumio volumio[4318]: info: CoreCommandRouter::volumioGetState Oct 06 16:19:03 volumio volumio[4318]: info: CorePlayQueue::getTrack 0 Oct 06 16:19:03 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 06 16:19:03 volumio volumio[4318]: info: CoreCommandRouter::volumioGetState Oct 06 16:19:03 volumio volumio[4318]: info: CorePlayQueue::getTrack 0 Oct 06 16:19:03 volumio volumio[4318]: info: Listing playlists Oct 06 16:19:03 volumio volumio[4318]: info: CoreCommandRouter::volumioGetQueue Oct 06 16:19:03 volumio volumio[4318]: info: CoreStateMachine::getQueue Oct 06 16:19:03 volumio volumio[4318]: info: CorePlayQueue::getQueue Oct 06 16:19:04 volumio volumio[4318]: info: go-librespot daemon successfully initialized Oct 06 16:19:06 volumio volumio[4318]: info: Volumio called home Oct 06 16:19:07 volumio volumio[4318]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Oct 06 16:19:07 volumio go-librespot[4459]: time="2024-10-06T16:19:07+02:00" level=debug msg="authenticated as gronk" Oct 06 16:19:07 volumio volumio[4318]: info: Initializing connection to go-librespot Websocket Oct 06 16:19:07 volumio go-librespot[4459]: time="2024-10-06T16:19:07+02:00" level=debug msg="new websocket client" Oct 06 16:19:07 volumio volumio[4318]: info: Connection to go-librespot Websocket established Oct 06 16:19:08 volumio volumio[4318]: info: Cannot mount NAS Diskstation at system boot, trial number 3 ,retrying in 5 seconds Oct 06 16:19:08 volumio sudo[4498]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 06 16:19:08 volumio sudo[4498]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:19:08 volumio sudo[4498]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:08 volumio sudo[4501]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 06 16:19:08 volumio sudo[4501]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:19:08 volumio sudo[4501]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:08 volumio sudo[4504]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Oct 06 16:19:08 volumio sudo[4504]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:19:08 volumio sudo[4504]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:08 volumio volumio[4318]: info: Upmpdcli Daemon Started Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Oct 06 16:19:10 volumio volumio[4318]: info: Adding plugin bluetooth to MyMusic Plugins Oct 06 16:19:10 volumio volumio[4318]: info: Adding plugin multiroom to MyMusic Plugins Oct 06 16:19:10 volumio volumio[4318]: info: Adding plugin metavolumio to MyMusic Plugins Oct 06 16:19:10 volumio volumio[4318]: info: Adding plugin cd_controller to MyMusic Plugins Oct 06 16:19:10 volumio volumio[4318]: info: Adding plugin smart_inputs to MyMusic Plugins Oct 06 16:19:10 volumio volumio[4318]: info: Adding plugin tidalconnect to MyMusic Plugins Oct 06 16:19:10 volumio volumio[4318]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Oct 06 16:19:11 volumio volumio[4318]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Oct 06 16:19:11 volumio volumio[4318]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Oct 06 16:19:11 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:19:11 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 06 16:19:11 volumio volumio[4318]: info: Starting MyVolumio Remote Streaming Endpoints Oct 06 16:19:11 volumio volumio[4318]: info: MyVolumio login type: Token Oct 06 16:19:11 volumio volumio[4318]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Oct 06 16:19:11 volumio volumio[4318]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Oct 06 16:19:11 volumio volumio[4318]: info: Starting Streaming Service Transparent Proxy Oct 06 16:19:11 volumio volumio[4318]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Oct 06 16:19:11 volumio volumio[4318]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Oct 06 16:19:11 volumio volumio[4318]: info: Streaming services startup Oct 06 16:19:11 volumio volumio[4318]: info: Starting Streaming Daemon Oct 06 16:19:12 volumio sudo[4513]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 06 16:19:12 volumio sudo[4513]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:19:12 volumio sudo[4513]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:12 volumio volumio[4318]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Oct 06 16:19:12 volumio volumio[4318]: info: Getting Spotify volume Oct 06 16:19:12 volumio volumio[4318]: error: Cannot start Volumio Streaming Daemon Oct 06 16:19:12 volumio volumio[4318]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 06 16:19:12 volumio volumio[4318]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 06 16:19:12 volumio volumio[4318]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Oct 06 16:19:12 volumio volumio[4318]: info: CoreCommandRouter::volumioGetState Oct 06 16:19:12 volumio volumio[4318]: info: CorePlayQueue::getTrack 0 Oct 06 16:19:12 volumio volumio[4318]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 06 16:19:12 volumio volumio[4318]: STREAMING PROXY: Starting server on port 3245 Oct 06 16:19:12 volumio volumio[4318]: Node JS runtime: 14 Oct 06 16:19:13 volumio volumio[4318]: info: MyVolumio token set successfully Oct 06 16:19:13 volumio volumio[4318]: info: MYVOLUMIO: Adding device Oct 06 16:19:13 volumio volumio[4318]: info: MYVOLUMIO: Evaluating Server Oct 06 16:19:13 volumio volumio[4318]: info: Cannot mount NAS Diskstation at system boot, trial number 4 ,retrying in 5 seconds Oct 06 16:19:13 volumio go-librespot[4459]: time="2024-10-06T16:19:13+02:00" level=debug msg="dealer connection opened" Oct 06 16:19:13 volumio go-librespot[4459]: time="2024-10-06T16:19:13+02:00" level=debug msg="initializing zeroconf session, username: gronk" Oct 06 16:19:13 volumio go-librespot[4459]: time="2024-10-06T16:19:13+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 06 16:19:13 volumio go-librespot[4459]: time="2024-10-06T16:19:13+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 06 16:19:13 volumio go-librespot[4459]: time="2024-10-06T16:19:13+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 06 16:19:13 volumio go-librespot[4459]: time="2024-10-06T16:19:13+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 06 16:19:13 volumio go-librespot[4459]: time="2024-10-06T16:19:13+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 505" Oct 06 16:19:13 volumio go-librespot[4459]: time="2024-10-06T16:19:13+02:00" level=debug msg="autoplay enabled: false" Oct 06 16:19:13 volumio go-librespot[4459]: time="2024-10-06T16:19:13+02:00" level=debug msg="received connection id: MzA4Y2YxMTYtNDRlMi00NjViLTliMmEtYmNlNzVmZGY2Y2M3K2RlYWxlcit0Y3A6Ly8wYWNhNTkwYy5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArNkEzNjgzRUEzNkUyRUFBNUYyOTEyRTMzM0QxODE5RDMwNDM0MjE1NEMwMDlGRDc2RkFBOEE5RDc0QUI1N0NBMQ==" Oct 06 16:19:13 volumio volumio[4318]: info: Spotify volume: 100 Oct 06 16:19:13 volumio volumio[4318]: info: MyVolumio status changed Oct 06 16:19:13 volumio volumio[4318]: info: Streaming services startup Oct 06 16:19:13 volumio volumio[4318]: info: Starting Streaming Daemon Oct 06 16:19:13 volumio volumio[4318]: info: Removing browser output: myVolumio user plan is not superstar Oct 06 16:19:13 volumio volumio[4318]: info: Removing audio output: Oct 06 16:19:13 volumio volumio[4318]: info: Stoppping Tunnel 1 Oct 06 16:19:13 volumio sudo[4538]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 06 16:19:13 volumio sudo[4538]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:19:13 volumio sudo[4538]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:13 volumio volumio[4318]: error: Cannot start Volumio Streaming Daemon Oct 06 16:19:13 volumio sudo[4541]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 06 16:19:13 volumio volumio[4318]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 06 16:19:13 volumio volumio[4318]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 06 16:19:13 volumio sudo[4541]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 06 16:19:13 volumio sudo[4541]: pam_unix(sudo:session): session closed for user root Oct 06 16:19:13 volumio volumio[4318]: info: Remote SSH Stopped Oct 06 16:19:15 volumio volumio[4318]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 06 16:19:15 volumio volumio[4318]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 06 16:19:15 volumio volumio[4318]: TypeError: Cannot read property 'length' of undefined Oct 06 16:19:15 volumio volumio[4318]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Oct 06 16:19:15 volumio volumio[4318]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Oct 06 16:19:15 volumio volumio[4318]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Oct 06 16:19:15 volumio volumio[4318]: at Parser.emit (events.js:315:20) Oct 06 16:19:15 volumio volumio[4318]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Oct 06 16:19:15 volumio volumio[4318]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Oct 06 16:19:15 volumio volumio[4318]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Oct 06 16:19:15 volumio volumio[4318]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Oct 06 16:19:15 volumio volumio[4318]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Oct 06 16:19:15 volumio volumio[4318]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Oct 06 16:19:15 volumio volumio[4318]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Oct 06 16:19:15 volumio volumio[4318]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Oct 06 16:19:15 volumio volumio[4318]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Oct 06 16:19:15 volumio volumio[4318]: at IncomingMessage.emit (events.js:327:22) Oct 06 16:19:15 volumio volumio[4318]: at endReadableNT (internal/streams/readable.js:1327:12) Oct 06 16:19:15 volumio volumio[4318]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Oct 06 16:19:15 volumio volumio[4318]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 06 16:19:15 volumio sudo[4590]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-06 16:18 Oct 06 16:19:15 volumio sudo[4590]: 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="bba9e3185e150dd0995f9a49355b34fc6218d5a2" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8aa57e3ae5b742ea1069404608336a9884ccfb4e" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 17 Sep 2024 05:01:09 PM CEST" VOLUMIO_VERSION="3.757" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="e0a6dc7e914e3fb93cbf2123f2f73eac"