-- Logs begin at Thu 2019-02-14 02:11:59 PST, end at Fri 2024-10-25 20:47:08 PDT. -- Oct 25 20:46:00 volumio volumio[17837]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:00 volumio volumio[17837]: info: [1729914360002] CoreMusicLibrary::Adding element LastFM Oct 25 20:46:00 volumio volumio[17837]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:00 volumio volumio[17837]: Cannot find translation for source LastFM Oct 25 20:46:00 volumio volumio[17837]: info: [LastFM] scrobbler initiated! Oct 25 20:46:00 volumio volumio[17837]: info: [LastFM] extended logging: false Oct 25 20:46:00 volumio volumio[17837]: info: [LastFM] try scrobble stream/radio plays: true Oct 25 20:46:00 volumio volumio[17837]: info: [LastFM] Left init routine Oct 25 20:46:00 volumio volumio[17837]: info: [LastFM] Socket already connected: true Oct 25 20:46:00 volumio volumio[17837]: info: Volumio Calling Home Oct 25 20:46:00 volumio volumio[17837]: Unhandled rejection Error: No sockets available, cannot start. Oct 25 20:46:00 volumio volumio[17837]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Oct 25 20:46:00 volumio volumio[17837]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Oct 25 20:46:00 volumio volumio[17837]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Oct 25 20:46:00 volumio volumio[17837]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Oct 25 20:46:00 volumio volumio[17837]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Oct 25 20:46:00 volumio volumio[17837]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Oct 25 20:46:00 volumio volumio[17837]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Oct 25 20:46:00 volumio volumio[17837]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Oct 25 20:46:00 volumio volumio[17837]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Oct 25 20:46:00 volumio volumio[17837]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Oct 25 20:46:00 volumio volumio[17837]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Oct 25 20:46:00 volumio volumio[17837]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Oct 25 20:46:00 volumio volumio[17837]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Oct 25 20:46:00 volumio volumio[17837]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Oct 25 20:46:00 volumio volumio[17837]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Oct 25 20:46:00 volumio volumio[17837]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 25 20:46:00 volumio volumio[17837]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:00 volumio volumio[17837]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Oct 25 20:46:00 volumio volumio[17837]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Oct 25 20:46:00 volumio volumio[17837]: errno: -16, Oct 25 20:46:00 volumio volumio[17837]: code: 'EBUSY', Oct 25 20:46:00 volumio volumio[17837]: syscall: 'getaddrinfo', Oct 25 20:46:00 volumio volumio[17837]: hostname: 'ws.audioscrobbler.com' Oct 25 20:46:00 volumio volumio[17837]: } Oct 25 20:46:00 volumio volumio[17837]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:00 volumio sudo[17993]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-25 20:45 Oct 25 20:46:00 volumio sudo[17993]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:00 volumio mpd[17948]: Oct 25 20:46 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 25 20:46:00 volumio sudo[17993]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:00 volumio volumio-remote-updater[662]: [2024-10-25 20:46:00] [info] asio async_read_at_least error: system:104 (Connection reset by peer) Oct 25 20:46:00 volumio volumio-remote-updater[662]: [2024-10-25 20:46:00] [error] handle_read_http_response error: websocketpp.transport:2 (Underlying Transport Error) Oct 25 20:46:00 volumio volumio-remote-updater[662]: [2024-10-25 20:46:00] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Oct 25 20:46:00 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 25 20:46:00 volumio systemd[1]: media-WD_BLACK.mount: Succeeded. Oct 25 20:46:00 volumio sudo[17934]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:00 volumio sudo[17924]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:00 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 25 20:46:00 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:00 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:00 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 25 20:46:00 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 98. Oct 25 20:46:00 volumio systemd[1]: Stopped Volumio Backend Module. Oct 25 20:46:00 volumio systemd[1]: Started Volumio Backend Module. Oct 25 20:46:00 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:00 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:00 volumio systemd[1]: Started Music Player Daemon. Oct 25 20:46:01 volumio volumio[18007]: info: ------------------------------------------- Oct 25 20:46:01 volumio volumio[18007]: info: ----- Volumio3 ---- Oct 25 20:46:01 volumio volumio[18007]: info: ------------------------------------------- Oct 25 20:46:01 volumio volumio[18007]: info: ----- System startup ---- Oct 25 20:46:01 volumio volumio[18007]: info: ------------------------------------------- Oct 25 20:46:02 volumio volumio[18007]: info: MYVOLUMIO Environment detected Oct 25 20:46:02 volumio volumio[18007]: info: Plugin folders cleanup Oct 25 20:46:02 volumio volumio[18007]: info: Scanning into folder /volumio/app/plugins/ Oct 25 20:46:02 volumio volumio[18007]: info: Scanning category audio_interface Oct 25 20:46:02 volumio volumio[18007]: info: Scanning category miscellanea Oct 25 20:46:02 volumio volumio[18007]: info: Scanning category music_service Oct 25 20:46:02 volumio volumio[18007]: info: Scanning category plugins.json Oct 25 20:46:02 volumio volumio[18007]: info: Scanning category system_controller Oct 25 20:46:02 volumio volumio[18007]: info: Scanning category user_interface Oct 25 20:46:02 volumio volumio[18007]: info: Scanning into folder /data/plugins/ Oct 25 20:46:02 volumio volumio[18007]: info: Scanning category music_service Oct 25 20:46:02 volumio volumio[18007]: info: Scanning category user_interface Oct 25 20:46:02 volumio volumio[18007]: info: Plugin folders cleanup completed Oct 25 20:46:02 volumio volumio[18007]: info: ------------------------------------------- Oct 25 20:46:02 volumio volumio[18007]: info: ----- Core plugins startup ---- Oct 25 20:46:02 volumio volumio[18007]: info: ------------------------------------------- Oct 25 20:46:02 volumio volumio[18007]: info: Loading plugins from folder /volumio/app/plugins/ Oct 25 20:46:02 volumio volumio[18007]: info: Adding plugin upnp to MyMusic Plugins Oct 25 20:46:02 volumio volumio[18007]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 25 20:46:02 volumio volumio[18007]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 25 20:46:02 volumio volumio[18007]: info: Loading plugins from folder /data/plugins/ Oct 25 20:46:02 volumio volumio[18007]: info: Loading plugin "system"... Oct 25 20:46:02 volumio volumio[18007]: info: Loading plugin "appearance"... Oct 25 20:46:02 volumio volumio[18007]: info: Loading plugin "network"... Oct 25 20:46:02 volumio volumio[18007]: info: Refreshing Cached IP Addresses Oct 25 20:46:02 volumio sudo[18036]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 25 20:46:02 volumio sudo[18036]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:02 volumio sudo[18036]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:02 volumio sudo[18038]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 25 20:46:02 volumio volumio[18007]: info: Loading plugin "services"... Oct 25 20:46:02 volumio sudo[18038]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:02 volumio volumio[18007]: info: Loading plugin "alsa_controller"... Oct 25 20:46:02 volumio sudo[18038]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:02 volumio sudo[18041]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 25 20:46:02 volumio sudo[18041]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:02 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:02 volumio volumio[18007]: info: Loading plugin "wizard"... Oct 25 20:46:03 volumio volumio[18007]: info: Loading plugin "networkfs"... Oct 25 20:46:03 volumio volumio[18007]: info: Starting Udev Watcher for removable devices Oct 25 20:46:03 volumio volumio[18007]: info: Ignoring mount for partition: boot Oct 25 20:46:03 volumio volumio[18007]: info: Ignoring mount for partition: volumio Oct 25 20:46:03 volumio volumio[18007]: info: Ignoring mount for partition: volumio_data Oct 25 20:46:03 volumio volumio[18007]: info: Mounting Device WD_BLACK Oct 25 20:46:03 volumio sudo[18050]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/WD_BLACK -o noatime Oct 25 20:46:03 volumio sudo[18050]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:03 volumio sudo[18050]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:03 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:03 volumio volumio[18007]: info: Loading plugin "volumio_command_line_client"... Oct 25 20:46:03 volumio volumio[18007]: info: Loading plugin "upnp"... Oct 25 20:46:03 volumio volumio[18007]: info: [1729914363305] Starting Upmpd Daemon Oct 25 20:46:03 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:03 volumio volumio[18007]: info: Loading plugin "my_music"... Oct 25 20:46:03 volumio volumio[18007]: info: Loading plugin "mpd"... Oct 25 20:46:03 volumio volumio[18007]: info: Loading plugin "upnp_browser"... Oct 25 20:46:03 volumio volumio[18007]: info: Loading plugin "alarm-clock"... Oct 25 20:46:03 volumio volumio[18007]: info: Loading plugin "airplay_emulation"... Oct 25 20:46:03 volumio volumio[18007]: info: Starting Shairport Sync Oct 25 20:46:03 volumio volumio[18007]: info: Loading plugin "last_100"... Oct 25 20:46:03 volumio volumio[18007]: info: Loading plugin "webradio"... Oct 25 20:46:03 volumio volumio[18007]: info: Loading plugin "i2s_dacs"... Oct 25 20:46:03 volumio volumio[18007]: info: Loading plugin "volumiodiscovery"... Oct 25 20:46:03 volumio volumio[18007]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:03 volumio volumio[18007]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:03 volumio node[18007]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:03 volumio volumio[18007]: *** WARNING *** For more information see Oct 25 20:46:03 volumio volumio[18007]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:03 volumio volumio[18007]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:03 volumio volumio[18007]: *** WARNING *** For more information see Oct 25 20:46:03 volumio node[18007]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:03 volumio node[18007]: *** WARNING *** For more information see Oct 25 20:46:03 volumio node[18007]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:03 volumio node[18007]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:03 volumio node[18007]: *** WARNING *** For more information see Oct 25 20:46:03 volumio volumio[18007]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 25 20:46:03 volumio volumio[18007]: info: Discovery: Started advertising with name: Volumio Oct 25 20:46:03 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:03 volumio volumio[18007]: info: Loading plugin "spop"... Oct 25 20:46:04 volumio volumio[18007]: info: Loading plugin "outputs"... Oct 25 20:46:04 volumio volumio[18007]: info: Loading plugin "albumart"... Oct 25 20:46:04 volumio volumio[18007]: info: Plugin example_plugin is not enabled Oct 25 20:46:04 volumio volumio[18007]: info: Loading plugin "inputs"... Oct 25 20:46:04 volumio volumio[18007]: info: Loading plugin "updater_comm"... Oct 25 20:46:04 volumio volumio[18007]: info: Plugin mpdemulation is not enabled Oct 25 20:46:04 volumio volumio[18007]: info: Loading plugin "rest_api"... Oct 25 20:46:04 volumio volumio[18007]: info: Loading plugin "websocket"... Oct 25 20:46:04 volumio volumio[18007]: info: Starting Socket.io Server version 2.3.0 Oct 25 20:46:04 volumio volumio[18007]: info: Loading plugin "lastfm"... Oct 25 20:46:04 volumio volumio[18007]: Forking 3 albumart workers Oct 25 20:46:05 volumio volumio[18007]: info: Loading i18n strings for locale en Oct 25 20:46:05 volumio volumio[18007]: Updating browse sources language Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::initPlayerControls Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:05 volumio volumio[18007]: Express server listening on port 3000 Oct 25 20:46:05 volumio volumio[18007]: [Metrics] WebUI: 3s 596.78ms Oct 25 20:46:05 volumio volumio[18007]: info: CoreStateMachine::resetVolumioState Oct 25 20:46:05 volumio volumio[18007]: info: CoreStateMachine::getcurrentVolume Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::volumioRetrievevolume Oct 25 20:46:05 volumio volumio[18007]: info: CoreStateMachine::pushState Oct 25 20:46:05 volumio volumio[18007]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:05 volumio volumio[18007]: Starting albumart workers Oct 25 20:46:05 volumio volumio[18007]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 25 20:46:05 volumio volumio[18007]: Starting albumart workers Oct 25 20:46:05 volumio volumio[18007]: Starting albumart workers Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:05 volumio volumio[18007]: info: Reloading queue from file Oct 25 20:46:05 volumio volumio[18007]: info: CoreStateMachine::setRepeat false single undefined Oct 25 20:46:05 volumio volumio[18007]: info: CoreStateMachine::pushState Oct 25 20:46:05 volumio volumio[18007]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:05 volumio volumio[18007]: info: CoreStateMachine::setRandom false Oct 25 20:46:05 volumio volumio[18007]: info: CoreStateMachine::pushState Oct 25 20:46:05 volumio volumio[18007]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:05 volumio volumio[18007]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 25 20:46:05 volumio volumio[18007]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Oct 25 20:46:05 volumio volumio[18007]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 25 20:46:05 volumio volumio[18007]: info: Setting Device type: Raspberry PI Oct 25 20:46:05 volumio volumio[18007]: info: Completed loading Core Plugins Oct 25 20:46:05 volumio volumio[18007]: info: Preparing to generate the ALSA configuration file Oct 25 20:46:05 volumio volumio[18007]: info: Asound.conf file unchanged, so no further update is needed Oct 25 20:46:05 volumio volumio[18007]: info: Output device has changed, restarting MPD Oct 25 20:46:05 volumio volumio[18007]: info: Output device has changed, restarting Shairport Sync Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:05 volumio sudo[18093]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:05 volumio sudo[18093]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:05 volumio sudo[18093]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:05 volumio sudo[18094]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:05 volumio sudo[18094]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:05 volumio volumio[18007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:05 volumio volumio[18007]: info: ___________ START PLUGINS ___________ Oct 25 20:46:05 volumio volumio[18007]: info: ControllerMpd::onStart: Initializing MPD Oct 25 20:46:05 volumio volumio[18007]: info: Creating MPD Configuration file Oct 25 20:46:05 volumio systemd[1]: Stopping Music Player Daemon... Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:05 volumio volumio[18007]: info: [1729914365751] CoreMusicLibrary::Adding element Media Servers Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:05 volumio sudo[18101]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:05 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:05 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:05 volumio sudo[18101]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:05 volumio sudo[18101]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:05 volumio sudo[18103]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:05 volumio sudo[18103]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:05 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:05 volumio sudo[18041]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:05 volumio volumio[18007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:05 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 25 20:46:05 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:05 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:05 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:05 volumio volumio[18007]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:05 volumio volumio[18007]: info: [1729914365937] CoreMusicLibrary::Adding element Last_100 Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:05 volumio volumio[18007]: info: [1729914365940] CoreMusicLibrary::Adding element Webradio Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:05 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:05 volumio volumio[18007]: info: Initializing BBC Radios Oct 25 20:46:05 volumio sudo[18118]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 25 20:46:05 volumio sudo[18118]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:05 volumio sudo[18118]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:06 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:06 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:06 volumio volumio[18007]: info: Creating Spotify config file Oct 25 20:46:06 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:06 volumio volumio[18007]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:06 volumio volumio[18007]: info: [1729914366024] CoreMusicLibrary::Adding element LastFM Oct 25 20:46:06 volumio volumio[18007]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:06 volumio volumio[18007]: Cannot find translation for source LastFM Oct 25 20:46:06 volumio volumio[18007]: info: [LastFM] scrobbler initiated! Oct 25 20:46:06 volumio volumio[18007]: info: [LastFM] extended logging: false Oct 25 20:46:06 volumio volumio[18007]: info: [LastFM] try scrobble stream/radio plays: true Oct 25 20:46:06 volumio volumio[18007]: info: [LastFM] Left init routine Oct 25 20:46:06 volumio volumio[18007]: info: [LastFM] Socket already connected: true Oct 25 20:46:06 volumio volumio[18007]: info: Volumio Calling Home Oct 25 20:46:06 volumio volumio[18007]: Unhandled rejection Error: No sockets available, cannot start. Oct 25 20:46:06 volumio volumio[18007]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Oct 25 20:46:06 volumio volumio[18007]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Oct 25 20:46:06 volumio volumio[18007]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Oct 25 20:46:06 volumio volumio[18007]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Oct 25 20:46:06 volumio volumio[18007]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Oct 25 20:46:06 volumio volumio[18007]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Oct 25 20:46:06 volumio volumio[18007]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Oct 25 20:46:06 volumio volumio[18007]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Oct 25 20:46:06 volumio volumio[18007]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Oct 25 20:46:06 volumio volumio[18007]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Oct 25 20:46:06 volumio volumio[18007]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Oct 25 20:46:06 volumio volumio[18007]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Oct 25 20:46:06 volumio volumio[18007]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Oct 25 20:46:06 volumio volumio[18007]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Oct 25 20:46:06 volumio volumio[18007]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Oct 25 20:46:06 volumio volumio[18007]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 25 20:46:06 volumio volumio[18007]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:06 volumio volumio[18007]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Oct 25 20:46:06 volumio volumio[18007]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Oct 25 20:46:06 volumio volumio[18007]: errno: -16, Oct 25 20:46:06 volumio volumio[18007]: code: 'EBUSY', Oct 25 20:46:06 volumio volumio[18007]: syscall: 'getaddrinfo', Oct 25 20:46:06 volumio volumio[18007]: hostname: 'ws.audioscrobbler.com' Oct 25 20:46:06 volumio volumio[18007]: } Oct 25 20:46:06 volumio volumio[18007]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:06 volumio sudo[18162]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-25 20:45 Oct 25 20:46:06 volumio sudo[18162]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:06 volumio sudo[18162]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:06 volumio ntpd[808]: error resolving pool 1.debian.pool.ntp.org: System error (-11) Oct 25 20:46:06 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 25 20:46:06 volumio sudo[18103]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:06 volumio sudo[18094]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:06 volumio systemd[1]: media-WD_BLACK.mount: Succeeded. Oct 25 20:46:06 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 25 20:46:06 volumio mpd[18140]: Oct 25 20:46 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 25 20:46:06 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:06 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:06 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 25 20:46:06 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 99. Oct 25 20:46:06 volumio systemd[1]: Stopped Volumio Backend Module. Oct 25 20:46:06 volumio systemd[1]: Started Volumio Backend Module. Oct 25 20:46:06 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:06 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:07 volumio systemd[1]: Started Music Player Daemon. Oct 25 20:46:07 volumio ntpd[808]: error resolving pool 3.debian.pool.ntp.org: System error (-11) Oct 25 20:46:07 volumio ntpd[808]: error resolving pool 0.debian.pool.ntp.org: System error (-11) Oct 25 20:46:07 volumio volumio[18176]: info: ------------------------------------------- Oct 25 20:46:07 volumio volumio[18176]: info: ----- Volumio3 ---- Oct 25 20:46:07 volumio volumio[18176]: info: ------------------------------------------- Oct 25 20:46:07 volumio volumio[18176]: info: ----- System startup ---- Oct 25 20:46:07 volumio volumio[18176]: info: ------------------------------------------- Oct 25 20:46:08 volumio volumio-remote-updater[662]: [2024-10-25 20:46:08] [connect] Successful connection Oct 25 20:46:08 volumio volumio[18176]: info: MYVOLUMIO Environment detected Oct 25 20:46:08 volumio volumio[18176]: info: Plugin folders cleanup Oct 25 20:46:08 volumio volumio[18176]: info: Scanning into folder /volumio/app/plugins/ Oct 25 20:46:08 volumio volumio[18176]: info: Scanning category audio_interface Oct 25 20:46:08 volumio volumio[18176]: info: Scanning category miscellanea Oct 25 20:46:08 volumio volumio[18176]: info: Scanning category music_service Oct 25 20:46:08 volumio volumio[18176]: info: Scanning category plugins.json Oct 25 20:46:08 volumio volumio[18176]: info: Scanning category system_controller Oct 25 20:46:08 volumio volumio[18176]: info: Scanning category user_interface Oct 25 20:46:08 volumio volumio[18176]: info: Scanning into folder /data/plugins/ Oct 25 20:46:08 volumio volumio[18176]: info: Scanning category music_service Oct 25 20:46:08 volumio volumio[18176]: info: Scanning category user_interface Oct 25 20:46:08 volumio volumio[18176]: info: Plugin folders cleanup completed Oct 25 20:46:08 volumio volumio[18176]: info: ------------------------------------------- Oct 25 20:46:08 volumio volumio[18176]: info: ----- Core plugins startup ---- Oct 25 20:46:08 volumio volumio[18176]: info: ------------------------------------------- Oct 25 20:46:08 volumio volumio[18176]: info: Loading plugins from folder /volumio/app/plugins/ Oct 25 20:46:08 volumio volumio[18176]: info: Adding plugin upnp to MyMusic Plugins Oct 25 20:46:08 volumio volumio[18176]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 25 20:46:08 volumio volumio[18176]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 25 20:46:08 volumio volumio[18176]: info: Loading plugins from folder /data/plugins/ Oct 25 20:46:08 volumio volumio[18176]: info: Loading plugin "system"... Oct 25 20:46:08 volumio volumio[18176]: info: Loading plugin "appearance"... Oct 25 20:46:08 volumio ntpd[808]: error resolving pool 2.debian.pool.ntp.org: System error (-11) Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "network"... Oct 25 20:46:09 volumio volumio[18176]: info: Refreshing Cached IP Addresses Oct 25 20:46:09 volumio sudo[18205]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 25 20:46:09 volumio sudo[18205]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:09 volumio sudo[18205]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:09 volumio sudo[18207]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 25 20:46:09 volumio sudo[18207]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "services"... Oct 25 20:46:09 volumio sudo[18207]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "alsa_controller"... Oct 25 20:46:09 volumio sudo[18210]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 25 20:46:09 volumio sudo[18210]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:09 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "wizard"... Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "networkfs"... Oct 25 20:46:09 volumio volumio[18176]: info: Starting Udev Watcher for removable devices Oct 25 20:46:09 volumio volumio[18176]: info: Ignoring mount for partition: boot Oct 25 20:46:09 volumio volumio[18176]: info: Ignoring mount for partition: volumio Oct 25 20:46:09 volumio volumio[18176]: info: Ignoring mount for partition: volumio_data Oct 25 20:46:09 volumio volumio[18176]: info: Mounting Device WD_BLACK Oct 25 20:46:09 volumio sudo[18219]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/WD_BLACK -o noatime Oct 25 20:46:09 volumio sudo[18219]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:09 volumio sudo[18219]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:09 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "volumio_command_line_client"... Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "upnp"... Oct 25 20:46:09 volumio volumio[18176]: info: [1729914369408] Starting Upmpd Daemon Oct 25 20:46:09 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "my_music"... Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "mpd"... Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "upnp_browser"... Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "alarm-clock"... Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "airplay_emulation"... Oct 25 20:46:09 volumio volumio[18176]: info: Starting Shairport Sync Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "last_100"... Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "webradio"... Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "i2s_dacs"... Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "volumiodiscovery"... Oct 25 20:46:09 volumio volumio[18176]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:09 volumio node[18176]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:09 volumio volumio[18176]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:09 volumio node[18176]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:09 volumio volumio[18176]: *** WARNING *** For more information see Oct 25 20:46:09 volumio node[18176]: *** WARNING *** For more information see Oct 25 20:46:09 volumio volumio[18176]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:09 volumio node[18176]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:09 volumio volumio[18176]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:09 volumio node[18176]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:09 volumio volumio[18176]: *** WARNING *** For more information see Oct 25 20:46:09 volumio node[18176]: *** WARNING *** For more information see Oct 25 20:46:09 volumio volumio[18176]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 25 20:46:09 volumio volumio[18176]: info: Discovery: Started advertising with name: Volumio Oct 25 20:46:09 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:09 volumio volumio[18176]: info: Loading plugin "spop"... Oct 25 20:46:10 volumio volumio[18176]: info: Loading plugin "outputs"... Oct 25 20:46:10 volumio volumio[18176]: info: Loading plugin "albumart"... Oct 25 20:46:10 volumio volumio[18176]: info: Plugin example_plugin is not enabled Oct 25 20:46:10 volumio volumio[18176]: info: Loading plugin "inputs"... Oct 25 20:46:10 volumio volumio[18176]: info: Loading plugin "updater_comm"... Oct 25 20:46:10 volumio volumio[18176]: info: Plugin mpdemulation is not enabled Oct 25 20:46:10 volumio volumio[18176]: info: Loading plugin "rest_api"... Oct 25 20:46:10 volumio volumio[18176]: info: Loading plugin "websocket"... Oct 25 20:46:10 volumio volumio[18176]: info: Starting Socket.io Server version 2.3.0 Oct 25 20:46:10 volumio volumio[18176]: info: Loading plugin "lastfm"... Oct 25 20:46:10 volumio volumio[18176]: Forking 3 albumart workers Oct 25 20:46:11 volumio volumio[18176]: info: Loading i18n strings for locale en Oct 25 20:46:11 volumio volumio[18176]: Updating browse sources language Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::initPlayerControls Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:11 volumio volumio[18176]: Express server listening on port 3000 Oct 25 20:46:11 volumio volumio[18176]: [Metrics] WebUI: 3s 620.58ms Oct 25 20:46:11 volumio volumio[18176]: info: CoreStateMachine::resetVolumioState Oct 25 20:46:11 volumio volumio[18176]: info: CoreStateMachine::getcurrentVolume Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::volumioRetrievevolume Oct 25 20:46:11 volumio volumio[18176]: info: CoreStateMachine::pushState Oct 25 20:46:11 volumio volumio[18176]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:11 volumio volumio-remote-updater[662]: [2024-10-25 20:46:11] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1729914368 101 Oct 25 20:46:11 volumio volumio[18176]: 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: 1 Oct 25 20:46:11 volumio volumio[18176]: Starting albumart workers Oct 25 20:46:11 volumio volumio[18176]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Oct 25 20:46:11 volumio volumio[18176]: Starting albumart workers Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:11 volumio volumio[18176]: info: Reloading queue from file Oct 25 20:46:11 volumio volumio[18176]: Starting albumart workers Oct 25 20:46:11 volumio volumio[18176]: info: CoreStateMachine::setRepeat false single undefined Oct 25 20:46:11 volumio volumio[18176]: info: CoreStateMachine::pushState Oct 25 20:46:11 volumio volumio[18176]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:11 volumio volumio[18176]: info: CoreStateMachine::setRandom false Oct 25 20:46:11 volumio volumio[18176]: info: CoreStateMachine::pushState Oct 25 20:46:11 volumio volumio[18176]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:11 volumio volumio[18176]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 25 20:46:11 volumio volumio[18176]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Oct 25 20:46:11 volumio volumio[18176]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 25 20:46:11 volumio volumio[18176]: info: Setting Device type: Raspberry PI Oct 25 20:46:11 volumio volumio[18176]: info: Completed loading Core Plugins Oct 25 20:46:11 volumio volumio[18176]: info: Preparing to generate the ALSA configuration file Oct 25 20:46:11 volumio volumio[18176]: info: Asound.conf file unchanged, so no further update is needed Oct 25 20:46:11 volumio volumio[18176]: info: Output device has changed, restarting MPD Oct 25 20:46:11 volumio volumio[18176]: info: Output device has changed, restarting Shairport Sync Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:11 volumio sudo[18263]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:11 volumio sudo[18262]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:11 volumio sudo[18263]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:11 volumio sudo[18262]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:11 volumio sudo[18262]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:11 volumio systemd[1]: Stopping Music Player Daemon... Oct 25 20:46:11 volumio volumio[18176]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:11 volumio volumio[18176]: info: ___________ START PLUGINS ___________ Oct 25 20:46:11 volumio volumio[18176]: info: ControllerMpd::onStart: Initializing MPD Oct 25 20:46:11 volumio volumio[18176]: info: Creating MPD Configuration file Oct 25 20:46:11 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:11 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:11 volumio volumio[18176]: info: [1729914371874] CoreMusicLibrary::Adding element Media Servers Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:11 volumio sudo[18273]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:11 volumio sudo[18273]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:11 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:11 volumio sudo[18272]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:11 volumio sudo[18272]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:11 volumio sudo[18272]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:11 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 25 20:46:11 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:11 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:11 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:11 volumio sudo[18210]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:11 volumio volumio[18176]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:11 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:12 volumio volumio[18176]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:12 volumio volumio[18176]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:12 volumio sudo[18283]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 25 20:46:12 volumio sudo[18283]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:12 volumio volumio[18176]: info: [1729914372032] CoreMusicLibrary::Adding element Last_100 Oct 25 20:46:12 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:12 volumio volumio[18176]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:12 volumio volumio[18176]: info: [1729914372037] CoreMusicLibrary::Adding element Webradio Oct 25 20:46:12 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:12 volumio sudo[18283]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:12 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:12 volumio volumio[18176]: info: Initializing BBC Radios Oct 25 20:46:12 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:12 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:12 volumio volumio[18176]: info: Creating Spotify config file Oct 25 20:46:12 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:12 volumio volumio[18176]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:12 volumio volumio[18176]: info: [1729914372149] CoreMusicLibrary::Adding element LastFM Oct 25 20:46:12 volumio volumio[18176]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:12 volumio volumio[18176]: Cannot find translation for source LastFM Oct 25 20:46:12 volumio volumio[18176]: info: [LastFM] scrobbler initiated! Oct 25 20:46:12 volumio volumio[18176]: info: [LastFM] extended logging: false Oct 25 20:46:12 volumio volumio[18176]: info: [LastFM] try scrobble stream/radio plays: true Oct 25 20:46:12 volumio volumio[18176]: info: [LastFM] Left init routine Oct 25 20:46:12 volumio volumio[18176]: info: [LastFM] Socket already connected: true Oct 25 20:46:12 volumio volumio[18176]: info: Volumio Calling Home Oct 25 20:46:12 volumio volumio[18176]: Unhandled rejection Error: No sockets available, cannot start. Oct 25 20:46:12 volumio volumio[18176]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Oct 25 20:46:12 volumio volumio[18176]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Oct 25 20:46:12 volumio volumio[18176]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Oct 25 20:46:12 volumio volumio[18176]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Oct 25 20:46:12 volumio volumio[18176]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Oct 25 20:46:12 volumio volumio[18176]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Oct 25 20:46:12 volumio volumio[18176]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Oct 25 20:46:12 volumio volumio[18176]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Oct 25 20:46:12 volumio volumio[18176]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Oct 25 20:46:12 volumio volumio[18176]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Oct 25 20:46:12 volumio volumio[18176]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Oct 25 20:46:12 volumio volumio[18176]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Oct 25 20:46:12 volumio volumio[18176]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Oct 25 20:46:12 volumio volumio[18176]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Oct 25 20:46:12 volumio volumio[18176]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Oct 25 20:46:12 volumio volumio[18176]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 25 20:46:12 volumio volumio[18176]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:12 volumio volumio[18176]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Oct 25 20:46:12 volumio volumio[18176]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Oct 25 20:46:12 volumio volumio[18176]: errno: -16, Oct 25 20:46:12 volumio volumio[18176]: code: 'EBUSY', Oct 25 20:46:12 volumio volumio[18176]: syscall: 'getaddrinfo', Oct 25 20:46:12 volumio volumio[18176]: hostname: 'ws.audioscrobbler.com' Oct 25 20:46:12 volumio volumio[18176]: } Oct 25 20:46:12 volumio volumio[18176]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:12 volumio sudo[18331]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-25 20:45 Oct 25 20:46:12 volumio sudo[18331]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:12 volumio sudo[18331]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:12 volumio mpd[18300]: Oct 25 20:46 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 25 20:46:12 volumio volumio-remote-updater[662]: [2024-10-25 20:46:12] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 25 20:46:12 volumio volumio-remote-updater[662]: [2024-10-25 20:46:12] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 25 20:46:12 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 25 20:46:12 volumio systemd[1]: media-WD_BLACK.mount: Succeeded. Oct 25 20:46:12 volumio sudo[18263]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:12 volumio sudo[18273]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:12 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 25 20:46:13 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:13 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:13 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 25 20:46:13 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 100. Oct 25 20:46:13 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:13 volumio systemd[1]: Stopped Volumio Backend Module. Oct 25 20:46:13 volumio systemd[1]: Started Volumio Backend Module. Oct 25 20:46:13 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:13 volumio systemd[1]: Started Music Player Daemon. Oct 25 20:46:14 volumio volumio[18383]: info: ------------------------------------------- Oct 25 20:46:14 volumio volumio[18383]: info: ----- Volumio3 ---- Oct 25 20:46:14 volumio volumio[18383]: info: ------------------------------------------- Oct 25 20:46:14 volumio volumio[18383]: info: ----- System startup ---- Oct 25 20:46:14 volumio volumio[18383]: info: ------------------------------------------- Oct 25 20:46:14 volumio volumio[18383]: info: MYVOLUMIO Environment detected Oct 25 20:46:14 volumio volumio[18383]: info: Plugin folders cleanup Oct 25 20:46:14 volumio volumio[18383]: info: Scanning into folder /volumio/app/plugins/ Oct 25 20:46:14 volumio volumio[18383]: info: Scanning category audio_interface Oct 25 20:46:14 volumio volumio[18383]: info: Scanning category miscellanea Oct 25 20:46:14 volumio volumio[18383]: info: Scanning category music_service Oct 25 20:46:14 volumio volumio[18383]: info: Scanning category plugins.json Oct 25 20:46:14 volumio volumio[18383]: info: Scanning category system_controller Oct 25 20:46:14 volumio volumio[18383]: info: Scanning category user_interface Oct 25 20:46:14 volumio volumio[18383]: info: Scanning into folder /data/plugins/ Oct 25 20:46:14 volumio volumio[18383]: info: Scanning category music_service Oct 25 20:46:14 volumio volumio[18383]: info: Scanning category user_interface Oct 25 20:46:14 volumio volumio[18383]: info: Plugin folders cleanup completed Oct 25 20:46:14 volumio volumio[18383]: info: ------------------------------------------- Oct 25 20:46:14 volumio volumio[18383]: info: ----- Core plugins startup ---- Oct 25 20:46:14 volumio volumio[18383]: info: ------------------------------------------- Oct 25 20:46:14 volumio volumio[18383]: info: Loading plugins from folder /volumio/app/plugins/ Oct 25 20:46:14 volumio volumio[18383]: info: Adding plugin upnp to MyMusic Plugins Oct 25 20:46:14 volumio volumio[18383]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 25 20:46:14 volumio volumio[18383]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 25 20:46:14 volumio volumio[18383]: info: Loading plugins from folder /data/plugins/ Oct 25 20:46:14 volumio volumio[18383]: info: Loading plugin "system"... Oct 25 20:46:14 volumio volumio[18383]: info: Loading plugin "appearance"... Oct 25 20:46:15 volumio volumio[18383]: info: Loading plugin "network"... Oct 25 20:46:15 volumio volumio[18383]: info: Refreshing Cached IP Addresses Oct 25 20:46:15 volumio sudo[18411]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 25 20:46:15 volumio sudo[18411]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:15 volumio sudo[18411]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:15 volumio volumio[18383]: info: Loading plugin "services"... Oct 25 20:46:15 volumio sudo[18413]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 25 20:46:15 volumio sudo[18413]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:15 volumio volumio[18383]: info: Loading plugin "alsa_controller"... Oct 25 20:46:15 volumio sudo[18413]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:15 volumio sudo[18416]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 25 20:46:15 volumio sudo[18416]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:15 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:15 volumio volumio[18383]: info: Loading plugin "wizard"... Oct 25 20:46:15 volumio volumio[18383]: info: Loading plugin "networkfs"... Oct 25 20:46:15 volumio volumio[18383]: info: Starting Udev Watcher for removable devices Oct 25 20:46:15 volumio volumio[18383]: info: Ignoring mount for partition: boot Oct 25 20:46:15 volumio volumio[18383]: info: Ignoring mount for partition: volumio Oct 25 20:46:15 volumio volumio[18383]: info: Ignoring mount for partition: volumio_data Oct 25 20:46:15 volumio volumio[18383]: info: Mounting Device WD_BLACK Oct 25 20:46:15 volumio sudo[18425]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/WD_BLACK -o noatime Oct 25 20:46:15 volumio sudo[18425]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:15 volumio sudo[18425]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:15 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:15 volumio volumio[18383]: info: Loading plugin "volumio_command_line_client"... Oct 25 20:46:15 volumio volumio[18383]: info: Loading plugin "upnp"... Oct 25 20:46:15 volumio volumio[18383]: info: [1729914375514] Starting Upmpd Daemon Oct 25 20:46:15 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:15 volumio volumio[18383]: info: Loading plugin "my_music"... Oct 25 20:46:15 volumio volumio[18383]: info: Loading plugin "mpd"... Oct 25 20:46:15 volumio volumio[18383]: info: Loading plugin "upnp_browser"... Oct 25 20:46:15 volumio volumio[18383]: info: Loading plugin "alarm-clock"... Oct 25 20:46:15 volumio volumio[18383]: info: Loading plugin "airplay_emulation"... Oct 25 20:46:16 volumio volumio[18383]: info: Starting Shairport Sync Oct 25 20:46:16 volumio volumio[18383]: info: Loading plugin "last_100"... Oct 25 20:46:16 volumio volumio[18383]: info: Loading plugin "webradio"... Oct 25 20:46:16 volumio volumio[18383]: info: Loading plugin "i2s_dacs"... Oct 25 20:46:16 volumio volumio[18383]: info: Loading plugin "volumiodiscovery"... Oct 25 20:46:16 volumio volumio[18383]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:16 volumio volumio[18383]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:16 volumio node[18383]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:16 volumio volumio[18383]: *** WARNING *** For more information see Oct 25 20:46:16 volumio volumio[18383]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:16 volumio volumio[18383]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:16 volumio volumio[18383]: *** WARNING *** For more information see Oct 25 20:46:16 volumio node[18383]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:16 volumio node[18383]: *** WARNING *** For more information see Oct 25 20:46:16 volumio node[18383]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:16 volumio node[18383]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:16 volumio node[18383]: *** WARNING *** For more information see Oct 25 20:46:16 volumio volumio[18383]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 25 20:46:16 volumio volumio[18383]: info: Discovery: Started advertising with name: Volumio Oct 25 20:46:16 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:16 volumio volumio[18383]: info: Loading plugin "spop"... Oct 25 20:46:16 volumio volumio[18383]: info: Loading plugin "outputs"... Oct 25 20:46:16 volumio volumio[18383]: info: Loading plugin "albumart"... Oct 25 20:46:16 volumio volumio[18383]: info: Plugin example_plugin is not enabled Oct 25 20:46:16 volumio volumio[18383]: info: Loading plugin "inputs"... Oct 25 20:46:16 volumio volumio[18383]: info: Loading plugin "updater_comm"... Oct 25 20:46:16 volumio volumio[18383]: info: Plugin mpdemulation is not enabled Oct 25 20:46:16 volumio volumio[18383]: info: Loading plugin "rest_api"... Oct 25 20:46:16 volumio volumio[18383]: info: Loading plugin "websocket"... Oct 25 20:46:16 volumio volumio[18383]: info: Starting Socket.io Server version 2.3.0 Oct 25 20:46:16 volumio volumio[18383]: info: Loading plugin "lastfm"... Oct 25 20:46:16 volumio volumio[18383]: Forking 3 albumart workers Oct 25 20:46:17 volumio volumio[18383]: info: Loading i18n strings for locale en Oct 25 20:46:17 volumio volumio[18383]: Updating browse sources language Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::initPlayerControls Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:17 volumio volumio[18383]: Express server listening on port 3000 Oct 25 20:46:17 volumio volumio[18383]: [Metrics] WebUI: 3s 577.75ms Oct 25 20:46:17 volumio volumio[18383]: info: CoreStateMachine::resetVolumioState Oct 25 20:46:17 volumio volumio[18383]: info: CoreStateMachine::getcurrentVolume Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::volumioRetrievevolume Oct 25 20:46:17 volumio volumio[18383]: info: CoreStateMachine::pushState Oct 25 20:46:17 volumio volumio[18383]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:17 volumio volumio[18383]: Starting albumart workers Oct 25 20:46:17 volumio volumio[18383]: Starting albumart workers Oct 25 20:46:17 volumio volumio[18383]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:17 volumio volumio[18383]: info: Reloading queue from file Oct 25 20:46:17 volumio volumio[18383]: info: CoreStateMachine::setRepeat false single undefined Oct 25 20:46:17 volumio volumio[18383]: info: CoreStateMachine::pushState Oct 25 20:46:17 volumio volumio[18383]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:17 volumio volumio[18383]: info: CoreStateMachine::setRandom false Oct 25 20:46:17 volumio volumio[18383]: info: CoreStateMachine::pushState Oct 25 20:46:17 volumio volumio[18383]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:17 volumio volumio[18383]: info: Setting Device type: Raspberry PI Oct 25 20:46:17 volumio volumio[18383]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 25 20:46:17 volumio volumio[18383]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Oct 25 20:46:17 volumio volumio[18383]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 25 20:46:17 volumio volumio[18383]: info: Completed loading Core Plugins Oct 25 20:46:17 volumio volumio[18383]: info: Preparing to generate the ALSA configuration file Oct 25 20:46:17 volumio volumio[18383]: Starting albumart workers Oct 25 20:46:17 volumio volumio[18383]: info: Asound.conf file unchanged, so no further update is needed Oct 25 20:46:17 volumio volumio[18383]: info: Output device has changed, restarting MPD Oct 25 20:46:17 volumio volumio[18383]: info: Output device has changed, restarting Shairport Sync Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:17 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:17 volumio sudo[18468]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:17 volumio sudo[18468]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:17 volumio sudo[18470]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:17 volumio sudo[18470]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:17 volumio sudo[18468]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:17 volumio volumio-remote-updater[662]: [2024-10-25 20:46:17] [connect] Successful connection Oct 25 20:46:17 volumio systemd[1]: Stopping Music Player Daemon... Oct 25 20:46:17 volumio volumio[18383]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:17 volumio volumio[18383]: info: ___________ START PLUGINS ___________ Oct 25 20:46:17 volumio volumio[18383]: info: ControllerMpd::onStart: Initializing MPD Oct 25 20:46:17 volumio volumio[18383]: info: Creating MPD Configuration file Oct 25 20:46:17 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:17 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:17 volumio sudo[18481]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:17 volumio sudo[18481]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:18 volumio volumio[18383]: info: [1729914378002] CoreMusicLibrary::Adding element Media Servers Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:18 volumio sudo[18481]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:18 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:18 volumio sudo[18488]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:18 volumio sudo[18488]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:18 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 25 20:46:18 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:18 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:18 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:18 volumio sudo[18416]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:18 volumio volumio[18383]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:18 volumio sudo[18498]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 25 20:46:18 volumio sudo[18498]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:18 volumio sudo[18498]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:18 volumio volumio[18383]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:18 volumio volumio[18383]: info: [1729914378169] CoreMusicLibrary::Adding element Last_100 Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:18 volumio volumio[18383]: info: [1729914378172] CoreMusicLibrary::Adding element Webradio Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:18 volumio volumio[18383]: info: Initializing BBC Radios Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:18 volumio volumio[18383]: info: Creating Spotify config file Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:18 volumio volumio[18383]: info: [1729914378278] CoreMusicLibrary::Adding element LastFM Oct 25 20:46:18 volumio volumio[18383]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:18 volumio volumio[18383]: Cannot find translation for source LastFM Oct 25 20:46:18 volumio volumio[18383]: info: [LastFM] scrobbler initiated! Oct 25 20:46:18 volumio volumio[18383]: info: [LastFM] extended logging: false Oct 25 20:46:18 volumio volumio[18383]: info: [LastFM] try scrobble stream/radio plays: true Oct 25 20:46:18 volumio volumio[18383]: info: [LastFM] Left init routine Oct 25 20:46:18 volumio volumio[18383]: info: [LastFM] Socket already connected: true Oct 25 20:46:18 volumio volumio[18383]: info: Volumio Calling Home Oct 25 20:46:18 volumio volumio[18383]: Unhandled rejection Error: No sockets available, cannot start. Oct 25 20:46:18 volumio volumio[18383]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Oct 25 20:46:18 volumio volumio[18383]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Oct 25 20:46:18 volumio volumio[18383]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Oct 25 20:46:18 volumio volumio[18383]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Oct 25 20:46:18 volumio volumio[18383]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Oct 25 20:46:18 volumio volumio[18383]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Oct 25 20:46:18 volumio volumio[18383]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Oct 25 20:46:18 volumio volumio[18383]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Oct 25 20:46:18 volumio volumio[18383]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Oct 25 20:46:18 volumio volumio[18383]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Oct 25 20:46:18 volumio volumio[18383]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Oct 25 20:46:18 volumio volumio[18383]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Oct 25 20:46:18 volumio volumio[18383]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Oct 25 20:46:18 volumio volumio[18383]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Oct 25 20:46:18 volumio volumio[18383]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Oct 25 20:46:18 volumio volumio[18383]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 25 20:46:18 volumio volumio[18383]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:18 volumio volumio[18383]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Oct 25 20:46:18 volumio volumio[18383]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Oct 25 20:46:18 volumio volumio[18383]: errno: -16, Oct 25 20:46:18 volumio volumio[18383]: code: 'EBUSY', Oct 25 20:46:18 volumio volumio[18383]: syscall: 'getaddrinfo', Oct 25 20:46:18 volumio volumio[18383]: hostname: 'ws.audioscrobbler.com' Oct 25 20:46:18 volumio volumio[18383]: } Oct 25 20:46:18 volumio volumio[18383]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:18 volumio sudo[18537]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-25 20:45 Oct 25 20:46:18 volumio sudo[18537]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:18 volumio sudo[18537]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:18 volumio mpd[18506]: Oct 25 20:46 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 25 20:46:19 volumio volumio-remote-updater[662]: [2024-10-25 20:46:19] [info] asio async_read_at_least error: system:104 (Connection reset by peer) Oct 25 20:46:19 volumio volumio-remote-updater[662]: [2024-10-25 20:46:19] [error] handle_read_http_response error: websocketpp.transport:2 (Underlying Transport Error) Oct 25 20:46:19 volumio volumio-remote-updater[662]: [2024-10-25 20:46:19] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Oct 25 20:46:19 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 25 20:46:19 volumio sudo[18488]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:19 volumio systemd[1]: media-WD_BLACK.mount: Succeeded. Oct 25 20:46:19 volumio sudo[18470]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:19 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 25 20:46:19 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:19 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:19 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 25 20:46:19 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 101. Oct 25 20:46:19 volumio systemd[1]: Started Music Player Daemon. Oct 25 20:46:19 volumio systemd[1]: Stopped Volumio Backend Module. Oct 25 20:46:19 volumio systemd[1]: Started Volumio Backend Module. Oct 25 20:46:19 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:19 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:20 volumio volumio[18552]: info: ------------------------------------------- Oct 25 20:46:20 volumio volumio[18552]: info: ----- Volumio3 ---- Oct 25 20:46:20 volumio volumio[18552]: info: ------------------------------------------- Oct 25 20:46:20 volumio volumio[18552]: info: ----- System startup ---- Oct 25 20:46:20 volumio volumio[18552]: info: ------------------------------------------- Oct 25 20:46:20 volumio volumio[18552]: info: MYVOLUMIO Environment detected Oct 25 20:46:20 volumio volumio[18552]: info: Plugin folders cleanup Oct 25 20:46:20 volumio volumio[18552]: info: Scanning into folder /volumio/app/plugins/ Oct 25 20:46:20 volumio volumio[18552]: info: Scanning category audio_interface Oct 25 20:46:20 volumio volumio[18552]: info: Scanning category miscellanea Oct 25 20:46:20 volumio volumio[18552]: info: Scanning category music_service Oct 25 20:46:20 volumio volumio[18552]: info: Scanning category plugins.json Oct 25 20:46:20 volumio volumio[18552]: info: Scanning category system_controller Oct 25 20:46:20 volumio volumio[18552]: info: Scanning category user_interface Oct 25 20:46:20 volumio volumio[18552]: info: Scanning into folder /data/plugins/ Oct 25 20:46:20 volumio volumio[18552]: info: Scanning category music_service Oct 25 20:46:20 volumio volumio[18552]: info: Scanning category user_interface Oct 25 20:46:20 volumio volumio[18552]: info: Plugin folders cleanup completed Oct 25 20:46:20 volumio volumio[18552]: info: ------------------------------------------- Oct 25 20:46:20 volumio volumio[18552]: info: ----- Core plugins startup ---- Oct 25 20:46:20 volumio volumio[18552]: info: ------------------------------------------- Oct 25 20:46:20 volumio volumio[18552]: info: Loading plugins from folder /volumio/app/plugins/ Oct 25 20:46:20 volumio volumio[18552]: info: Adding plugin upnp to MyMusic Plugins Oct 25 20:46:20 volumio volumio[18552]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 25 20:46:20 volumio volumio[18552]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 25 20:46:20 volumio volumio[18552]: info: Loading plugins from folder /data/plugins/ Oct 25 20:46:20 volumio volumio[18552]: info: Loading plugin "system"... Oct 25 20:46:20 volumio volumio[18552]: info: Loading plugin "appearance"... Oct 25 20:46:21 volumio volumio[18552]: info: Loading plugin "network"... Oct 25 20:46:21 volumio volumio[18552]: info: Refreshing Cached IP Addresses Oct 25 20:46:21 volumio sudo[18579]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 25 20:46:21 volumio sudo[18579]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:21 volumio sudo[18579]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:21 volumio volumio[18552]: info: Loading plugin "services"... Oct 25 20:46:21 volumio sudo[18581]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 25 20:46:21 volumio volumio[18552]: info: Loading plugin "alsa_controller"... Oct 25 20:46:21 volumio sudo[18581]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:21 volumio sudo[18581]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:21 volumio sudo[18584]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 25 20:46:21 volumio sudo[18584]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:21 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:21 volumio volumio[18552]: info: Loading plugin "wizard"... Oct 25 20:46:21 volumio volumio[18552]: info: Loading plugin "networkfs"... Oct 25 20:46:21 volumio volumio[18552]: info: Starting Udev Watcher for removable devices Oct 25 20:46:21 volumio volumio[18552]: info: Ignoring mount for partition: boot Oct 25 20:46:21 volumio volumio[18552]: info: Ignoring mount for partition: volumio Oct 25 20:46:21 volumio volumio[18552]: info: Ignoring mount for partition: volumio_data Oct 25 20:46:21 volumio volumio[18552]: info: Mounting Device WD_BLACK Oct 25 20:46:21 volumio sudo[18593]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/WD_BLACK -o noatime Oct 25 20:46:21 volumio sudo[18593]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:21 volumio sudo[18593]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:21 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:21 volumio volumio[18552]: info: Loading plugin "volumio_command_line_client"... Oct 25 20:46:21 volumio volumio[18552]: info: Loading plugin "upnp"... Oct 25 20:46:21 volumio volumio[18552]: info: [1729914381678] Starting Upmpd Daemon Oct 25 20:46:21 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:21 volumio volumio[18552]: info: Loading plugin "my_music"... Oct 25 20:46:21 volumio volumio[18552]: info: Loading plugin "mpd"... Oct 25 20:46:21 volumio volumio[18552]: info: Loading plugin "upnp_browser"... Oct 25 20:46:22 volumio volumio[18552]: info: Loading plugin "alarm-clock"... Oct 25 20:46:22 volumio volumio[18552]: info: Loading plugin "airplay_emulation"... Oct 25 20:46:22 volumio volumio[18552]: info: Starting Shairport Sync Oct 25 20:46:22 volumio volumio[18552]: info: Loading plugin "last_100"... Oct 25 20:46:22 volumio volumio[18552]: info: Loading plugin "webradio"... Oct 25 20:46:22 volumio volumio[18552]: info: Loading plugin "i2s_dacs"... Oct 25 20:46:22 volumio volumio[18552]: info: Loading plugin "volumiodiscovery"... Oct 25 20:46:22 volumio volumio[18552]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:22 volumio volumio[18552]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:22 volumio node[18552]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:22 volumio volumio[18552]: *** WARNING *** For more information see Oct 25 20:46:22 volumio volumio[18552]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:22 volumio volumio[18552]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:22 volumio volumio[18552]: *** WARNING *** For more information see Oct 25 20:46:22 volumio node[18552]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:22 volumio node[18552]: *** WARNING *** For more information see Oct 25 20:46:22 volumio node[18552]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:22 volumio node[18552]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:22 volumio node[18552]: *** WARNING *** For more information see Oct 25 20:46:22 volumio volumio[18552]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 25 20:46:22 volumio volumio[18552]: info: Discovery: Started advertising with name: Volumio Oct 25 20:46:22 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:22 volumio volumio[18552]: info: Loading plugin "spop"... Oct 25 20:46:22 volumio volumio[18552]: info: Loading plugin "outputs"... Oct 25 20:46:22 volumio volumio[18552]: info: Loading plugin "albumart"... Oct 25 20:46:22 volumio volumio[18552]: info: Plugin example_plugin is not enabled Oct 25 20:46:22 volumio volumio[18552]: info: Loading plugin "inputs"... Oct 25 20:46:22 volumio volumio[18552]: info: Loading plugin "updater_comm"... Oct 25 20:46:23 volumio volumio[18552]: info: Plugin mpdemulation is not enabled Oct 25 20:46:23 volumio volumio[18552]: info: Loading plugin "rest_api"... Oct 25 20:46:23 volumio volumio[18552]: info: Loading plugin "websocket"... Oct 25 20:46:23 volumio volumio[18552]: info: Starting Socket.io Server version 2.3.0 Oct 25 20:46:23 volumio volumio[18552]: info: Loading plugin "lastfm"... Oct 25 20:46:23 volumio volumio[18552]: Forking 3 albumart workers Oct 25 20:46:23 volumio volumio[18552]: info: Loading i18n strings for locale en Oct 25 20:46:23 volumio volumio[18552]: Updating browse sources language Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::initPlayerControls Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:23 volumio volumio[18552]: Express server listening on port 3000 Oct 25 20:46:23 volumio volumio[18552]: [Metrics] WebUI: 3s 604.36ms Oct 25 20:46:23 volumio volumio[18552]: info: CoreStateMachine::resetVolumioState Oct 25 20:46:23 volumio volumio[18552]: info: CoreStateMachine::getcurrentVolume Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::volumioRetrievevolume Oct 25 20:46:23 volumio volumio[18552]: info: CoreStateMachine::pushState Oct 25 20:46:23 volumio volumio[18552]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:23 volumio volumio[18552]: Starting albumart workers Oct 25 20:46:23 volumio volumio[18552]: Starting albumart workers Oct 25 20:46:23 volumio volumio[18552]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:23 volumio volumio[18552]: info: Reloading queue from file Oct 25 20:46:23 volumio volumio[18552]: info: CoreStateMachine::setRepeat false single undefined Oct 25 20:46:23 volumio volumio[18552]: info: CoreStateMachine::pushState Oct 25 20:46:23 volumio volumio[18552]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:23 volumio volumio[18552]: Starting albumart workers Oct 25 20:46:23 volumio volumio[18552]: info: CoreStateMachine::setRandom false Oct 25 20:46:23 volumio volumio[18552]: info: CoreStateMachine::pushState Oct 25 20:46:23 volumio volumio[18552]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:23 volumio volumio[18552]: info: Setting Device type: Raspberry PI Oct 25 20:46:23 volumio volumio[18552]: info: Completed loading Core Plugins Oct 25 20:46:23 volumio volumio[18552]: info: Preparing to generate the ALSA configuration file Oct 25 20:46:23 volumio volumio[18552]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 25 20:46:23 volumio volumio[18552]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Oct 25 20:46:23 volumio volumio[18552]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 25 20:46:23 volumio volumio[18552]: info: Asound.conf file unchanged, so no further update is needed Oct 25 20:46:23 volumio volumio[18552]: info: Output device has changed, restarting MPD Oct 25 20:46:23 volumio volumio[18552]: info: Output device has changed, restarting Shairport Sync Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:23 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:23 volumio sudo[18636]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:23 volumio sudo[18636]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:23 volumio sudo[18636]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:23 volumio sudo[18637]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:23 volumio sudo[18637]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:24 volumio volumio[18552]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:24 volumio systemd[1]: Stopping Music Player Daemon... Oct 25 20:46:24 volumio volumio[18552]: info: ___________ START PLUGINS ___________ Oct 25 20:46:24 volumio volumio[18552]: info: ControllerMpd::onStart: Initializing MPD Oct 25 20:46:24 volumio volumio[18552]: info: Creating MPD Configuration file Oct 25 20:46:24 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:24 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:24 volumio volumio[18552]: info: [1729914384119] CoreMusicLibrary::Adding element Media Servers Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:24 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:24 volumio sudo[18647]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:24 volumio sudo[18647]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:24 volumio sudo[18645]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:24 volumio sudo[18645]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:24 volumio sudo[18645]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:24 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 25 20:46:24 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:24 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:24 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:24 volumio volumio[18552]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:24 volumio volumio[18552]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:24 volumio volumio[18552]: info: [1729914384266] CoreMusicLibrary::Adding element Last_100 Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:24 volumio volumio[18552]: info: [1729914384270] CoreMusicLibrary::Adding element Webradio Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:24 volumio sudo[18661]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 25 20:46:24 volumio sudo[18584]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:24 volumio sudo[18661]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:24 volumio volumio[18552]: info: Initializing BBC Radios Oct 25 20:46:24 volumio sudo[18661]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:24 volumio volumio[18552]: info: Creating Spotify config file Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:24 volumio volumio[18552]: info: [1729914384401] CoreMusicLibrary::Adding element LastFM Oct 25 20:46:24 volumio volumio[18552]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:24 volumio volumio[18552]: Cannot find translation for source LastFM Oct 25 20:46:24 volumio volumio[18552]: info: [LastFM] scrobbler initiated! Oct 25 20:46:24 volumio volumio[18552]: info: [LastFM] extended logging: false Oct 25 20:46:24 volumio volumio[18552]: info: [LastFM] try scrobble stream/radio plays: true Oct 25 20:46:24 volumio volumio[18552]: info: [LastFM] Left init routine Oct 25 20:46:24 volumio volumio[18552]: info: [LastFM] Socket already connected: true Oct 25 20:46:24 volumio volumio[18552]: info: Volumio Calling Home Oct 25 20:46:24 volumio volumio[18552]: Unhandled rejection Error: No sockets available, cannot start. Oct 25 20:46:24 volumio volumio[18552]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Oct 25 20:46:24 volumio volumio[18552]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Oct 25 20:46:24 volumio volumio[18552]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Oct 25 20:46:24 volumio volumio[18552]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Oct 25 20:46:24 volumio volumio[18552]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Oct 25 20:46:24 volumio volumio[18552]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Oct 25 20:46:24 volumio volumio[18552]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Oct 25 20:46:24 volumio volumio[18552]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Oct 25 20:46:24 volumio volumio[18552]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Oct 25 20:46:24 volumio volumio[18552]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Oct 25 20:46:24 volumio volumio[18552]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Oct 25 20:46:24 volumio volumio[18552]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Oct 25 20:46:24 volumio volumio[18552]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Oct 25 20:46:24 volumio volumio[18552]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Oct 25 20:46:24 volumio volumio[18552]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Oct 25 20:46:24 volumio volumio[18552]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 25 20:46:24 volumio volumio[18552]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:24 volumio volumio[18552]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Oct 25 20:46:24 volumio volumio[18552]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Oct 25 20:46:24 volumio volumio[18552]: errno: -16, Oct 25 20:46:24 volumio volumio[18552]: code: 'EBUSY', Oct 25 20:46:24 volumio volumio[18552]: syscall: 'getaddrinfo', Oct 25 20:46:24 volumio volumio[18552]: hostname: 'ws.audioscrobbler.com' Oct 25 20:46:24 volumio volumio[18552]: } Oct 25 20:46:24 volumio volumio[18552]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:24 volumio sudo[18705]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-25 20:45 Oct 25 20:46:24 volumio sudo[18705]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:25 volumio sudo[18705]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:25 volumio mpd[18674]: Oct 25 20:46 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 25 20:46:25 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 25 20:46:25 volumio sudo[18637]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:25 volumio systemd[1]: media-WD_BLACK.mount: Succeeded. Oct 25 20:46:25 volumio sudo[18647]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:25 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 25 20:46:25 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:25 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:25 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 25 20:46:25 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 102. Oct 25 20:46:25 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:25 volumio systemd[1]: Stopped Volumio Backend Module. Oct 25 20:46:25 volumio systemd[1]: Started Volumio Backend Module. Oct 25 20:46:25 volumio systemd[1]: Started Music Player Daemon. Oct 25 20:46:25 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:26 volumio volumio[18721]: info: ------------------------------------------- Oct 25 20:46:26 volumio volumio[18721]: info: ----- Volumio3 ---- Oct 25 20:46:26 volumio volumio[18721]: info: ------------------------------------------- Oct 25 20:46:26 volumio volumio[18721]: info: ----- System startup ---- Oct 25 20:46:26 volumio volumio[18721]: info: ------------------------------------------- Oct 25 20:46:26 volumio volumio-remote-updater[662]: [2024-10-25 20:46:26] [connect] Successful connection Oct 25 20:46:26 volumio volumio[18721]: info: MYVOLUMIO Environment detected Oct 25 20:46:26 volumio volumio[18721]: info: Plugin folders cleanup Oct 25 20:46:26 volumio volumio[18721]: info: Scanning into folder /volumio/app/plugins/ Oct 25 20:46:26 volumio volumio[18721]: info: Scanning category audio_interface Oct 25 20:46:26 volumio volumio[18721]: info: Scanning category miscellanea Oct 25 20:46:26 volumio volumio[18721]: info: Scanning category music_service Oct 25 20:46:26 volumio volumio[18721]: info: Scanning category plugins.json Oct 25 20:46:26 volumio volumio[18721]: info: Scanning category system_controller Oct 25 20:46:26 volumio volumio[18721]: info: Scanning category user_interface Oct 25 20:46:26 volumio volumio[18721]: info: Scanning into folder /data/plugins/ Oct 25 20:46:26 volumio volumio[18721]: info: Scanning category music_service Oct 25 20:46:26 volumio volumio[18721]: info: Scanning category user_interface Oct 25 20:46:26 volumio volumio[18721]: info: Plugin folders cleanup completed Oct 25 20:46:26 volumio volumio[18721]: info: ------------------------------------------- Oct 25 20:46:26 volumio volumio[18721]: info: ----- Core plugins startup ---- Oct 25 20:46:26 volumio volumio[18721]: info: ------------------------------------------- Oct 25 20:46:26 volumio volumio[18721]: info: Loading plugins from folder /volumio/app/plugins/ Oct 25 20:46:26 volumio volumio[18721]: info: Adding plugin upnp to MyMusic Plugins Oct 25 20:46:26 volumio volumio[18721]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 25 20:46:26 volumio volumio[18721]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 25 20:46:26 volumio volumio[18721]: info: Loading plugins from folder /data/plugins/ Oct 25 20:46:26 volumio volumio[18721]: info: Loading plugin "system"... Oct 25 20:46:26 volumio volumio[18721]: info: Loading plugin "appearance"... Oct 25 20:46:27 volumio volumio[18721]: info: Loading plugin "network"... Oct 25 20:46:27 volumio volumio[18721]: info: Refreshing Cached IP Addresses Oct 25 20:46:27 volumio sudo[18747]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 25 20:46:27 volumio sudo[18747]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:27 volumio sudo[18747]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:27 volumio sudo[18749]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 25 20:46:27 volumio volumio[18721]: info: Loading plugin "services"... Oct 25 20:46:27 volumio sudo[18749]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:27 volumio volumio[18721]: info: Loading plugin "alsa_controller"... Oct 25 20:46:27 volumio sudo[18749]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:27 volumio sudo[18752]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 25 20:46:27 volumio sudo[18752]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:27 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:27 volumio volumio[18721]: info: Loading plugin "wizard"... Oct 25 20:46:27 volumio volumio[18721]: info: Loading plugin "networkfs"... Oct 25 20:46:27 volumio volumio[18721]: info: Starting Udev Watcher for removable devices Oct 25 20:46:27 volumio volumio[18721]: info: Ignoring mount for partition: boot Oct 25 20:46:27 volumio volumio[18721]: info: Ignoring mount for partition: volumio Oct 25 20:46:27 volumio volumio[18721]: info: Ignoring mount for partition: volumio_data Oct 25 20:46:27 volumio volumio[18721]: info: Mounting Device WD_BLACK Oct 25 20:46:27 volumio sudo[18761]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/WD_BLACK -o noatime Oct 25 20:46:27 volumio sudo[18761]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:27 volumio sudo[18761]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:27 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:27 volumio volumio[18721]: info: Loading plugin "volumio_command_line_client"... Oct 25 20:46:27 volumio volumio[18721]: info: Loading plugin "upnp"... Oct 25 20:46:27 volumio volumio[18721]: info: [1729914387830] Starting Upmpd Daemon Oct 25 20:46:27 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:27 volumio volumio[18721]: info: Loading plugin "my_music"... Oct 25 20:46:27 volumio volumio[18721]: info: Loading plugin "mpd"... Oct 25 20:46:28 volumio volumio[18721]: info: Loading plugin "upnp_browser"... Oct 25 20:46:28 volumio volumio[18721]: info: Loading plugin "alarm-clock"... Oct 25 20:46:28 volumio volumio[18721]: info: Loading plugin "airplay_emulation"... Oct 25 20:46:28 volumio volumio[18721]: info: Starting Shairport Sync Oct 25 20:46:28 volumio volumio[18721]: info: Loading plugin "last_100"... Oct 25 20:46:28 volumio volumio[18721]: info: Loading plugin "webradio"... Oct 25 20:46:28 volumio volumio[18721]: info: Loading plugin "i2s_dacs"... Oct 25 20:46:28 volumio volumio[18721]: info: Loading plugin "volumiodiscovery"... Oct 25 20:46:28 volumio volumio[18721]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:28 volumio volumio[18721]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:28 volumio node[18721]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:28 volumio volumio[18721]: *** WARNING *** For more information see Oct 25 20:46:28 volumio volumio[18721]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:28 volumio volumio[18721]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:28 volumio volumio[18721]: *** WARNING *** For more information see Oct 25 20:46:28 volumio node[18721]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:28 volumio node[18721]: *** WARNING *** For more information see Oct 25 20:46:28 volumio node[18721]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:28 volumio node[18721]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:28 volumio node[18721]: *** WARNING *** For more information see Oct 25 20:46:28 volumio volumio[18721]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 25 20:46:28 volumio volumio[18721]: info: Discovery: Started advertising with name: Volumio Oct 25 20:46:28 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:28 volumio volumio[18721]: info: Loading plugin "spop"... Oct 25 20:46:29 volumio volumio[18721]: info: Loading plugin "outputs"... Oct 25 20:46:29 volumio volumio[18721]: info: Loading plugin "albumart"... Oct 25 20:46:29 volumio volumio[18721]: info: Plugin example_plugin is not enabled Oct 25 20:46:29 volumio volumio[18721]: info: Loading plugin "inputs"... Oct 25 20:46:29 volumio volumio[18721]: info: Loading plugin "updater_comm"... Oct 25 20:46:29 volumio volumio[18721]: info: Plugin mpdemulation is not enabled Oct 25 20:46:29 volumio volumio[18721]: info: Loading plugin "rest_api"... Oct 25 20:46:29 volumio volumio[18721]: info: Loading plugin "websocket"... Oct 25 20:46:29 volumio volumio[18721]: info: Starting Socket.io Server version 2.3.0 Oct 25 20:46:29 volumio volumio[18721]: info: Loading plugin "lastfm"... Oct 25 20:46:29 volumio volumio[18721]: Forking 3 albumart workers Oct 25 20:46:29 volumio volumio[18721]: info: Loading i18n strings for locale en Oct 25 20:46:29 volumio volumio[18721]: Updating browse sources language Oct 25 20:46:29 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:29 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:29 volumio volumio[18721]: info: CoreCommandRouter::initPlayerControls Oct 25 20:46:29 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:29 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:29 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:29 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:29 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:29 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:29 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:29 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:29 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:29 volumio volumio[18721]: Express server listening on port 3000 Oct 25 20:46:29 volumio volumio[18721]: [Metrics] WebUI: 3s 592.52ms Oct 25 20:46:29 volumio volumio[18721]: info: CoreStateMachine::resetVolumioState Oct 25 20:46:29 volumio volumio[18721]: info: CoreStateMachine::getcurrentVolume Oct 25 20:46:29 volumio volumio[18721]: info: CoreCommandRouter::volumioRetrievevolume Oct 25 20:46:29 volumio volumio[18721]: info: CoreStateMachine::pushState Oct 25 20:46:29 volumio volumio[18721]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:29 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:29 volumio volumio[18721]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:29 volumio volumio[18721]: Starting albumart workers Oct 25 20:46:29 volumio volumio[18721]: Starting albumart workers Oct 25 20:46:29 volumio volumio-remote-updater[662]: [2024-10-25 20:46:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1729914386 101 Oct 25 20:46:29 volumio volumio[18721]: 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: 1 Oct 25 20:46:29 volumio volumio[18721]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Oct 25 20:46:29 volumio volumio[18721]: Starting albumart workers Oct 25 20:46:29 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:29 volumio volumio[18721]: info: Reloading queue from file Oct 25 20:46:30 volumio volumio[18721]: info: CoreStateMachine::setRepeat false single undefined Oct 25 20:46:30 volumio volumio[18721]: info: CoreStateMachine::pushState Oct 25 20:46:30 volumio volumio[18721]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:30 volumio volumio[18721]: info: CoreStateMachine::setRandom false Oct 25 20:46:30 volumio volumio[18721]: info: CoreStateMachine::pushState Oct 25 20:46:30 volumio volumio[18721]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:30 volumio volumio[18721]: info: Setting Device type: Raspberry PI Oct 25 20:46:30 volumio volumio[18721]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 25 20:46:30 volumio volumio[18721]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Oct 25 20:46:30 volumio volumio[18721]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 25 20:46:30 volumio volumio[18721]: info: Completed loading Core Plugins Oct 25 20:46:30 volumio volumio[18721]: info: Preparing to generate the ALSA configuration file Oct 25 20:46:30 volumio volumio[18721]: info: Asound.conf file unchanged, so no further update is needed Oct 25 20:46:30 volumio volumio[18721]: info: Output device has changed, restarting MPD Oct 25 20:46:30 volumio volumio[18721]: info: Output device has changed, restarting Shairport Sync Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:30 volumio sudo[18806]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:30 volumio sudo[18803]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:30 volumio sudo[18803]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:30 volumio sudo[18806]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:30 volumio sudo[18803]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:30 volumio systemd[1]: Stopping Music Player Daemon... Oct 25 20:46:30 volumio volumio[18721]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:30 volumio volumio[18721]: info: ___________ START PLUGINS ___________ Oct 25 20:46:30 volumio volumio[18721]: info: ControllerMpd::onStart: Initializing MPD Oct 25 20:46:30 volumio volumio[18721]: info: Creating MPD Configuration file Oct 25 20:46:30 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:30 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:30 volumio volumio[18721]: info: [1729914390301] CoreMusicLibrary::Adding element Media Servers Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:30 volumio sudo[18821]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:30 volumio sudo[18821]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:30 volumio sudo[18821]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:30 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:30 volumio sudo[18824]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:30 volumio sudo[18824]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:30 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 25 20:46:30 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:30 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:30 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:30 volumio volumio[18721]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:30 volumio sudo[18752]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:30 volumio sudo[18834]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 25 20:46:30 volumio sudo[18834]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:30 volumio sudo[18834]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:30 volumio volumio[18721]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:30 volumio volumio[18721]: info: [1729914390477] CoreMusicLibrary::Adding element Last_100 Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:30 volumio volumio[18721]: info: [1729914390480] CoreMusicLibrary::Adding element Webradio Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:30 volumio volumio[18721]: info: Initializing BBC Radios Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:30 volumio volumio[18721]: info: Creating Spotify config file Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:30 volumio volumio[18721]: info: [1729914390575] CoreMusicLibrary::Adding element LastFM Oct 25 20:46:30 volumio volumio[18721]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:30 volumio volumio[18721]: Cannot find translation for source LastFM Oct 25 20:46:30 volumio volumio[18721]: info: [LastFM] scrobbler initiated! Oct 25 20:46:30 volumio volumio[18721]: info: [LastFM] extended logging: false Oct 25 20:46:30 volumio volumio[18721]: info: [LastFM] try scrobble stream/radio plays: true Oct 25 20:46:30 volumio volumio[18721]: info: [LastFM] Left init routine Oct 25 20:46:30 volumio volumio[18721]: info: [LastFM] Socket already connected: true Oct 25 20:46:30 volumio volumio[18721]: info: Volumio Calling Home Oct 25 20:46:30 volumio volumio[18721]: Unhandled rejection Error: No sockets available, cannot start. Oct 25 20:46:30 volumio volumio[18721]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Oct 25 20:46:30 volumio volumio[18721]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Oct 25 20:46:30 volumio volumio[18721]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Oct 25 20:46:30 volumio volumio[18721]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Oct 25 20:46:30 volumio volumio[18721]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Oct 25 20:46:30 volumio volumio[18721]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Oct 25 20:46:30 volumio volumio[18721]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Oct 25 20:46:30 volumio volumio[18721]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Oct 25 20:46:30 volumio volumio[18721]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Oct 25 20:46:30 volumio volumio[18721]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Oct 25 20:46:30 volumio volumio[18721]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Oct 25 20:46:30 volumio volumio[18721]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Oct 25 20:46:30 volumio volumio[18721]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Oct 25 20:46:30 volumio volumio[18721]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Oct 25 20:46:30 volumio volumio[18721]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Oct 25 20:46:30 volumio volumio[18721]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 25 20:46:30 volumio volumio[18721]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:30 volumio volumio[18721]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Oct 25 20:46:30 volumio volumio[18721]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Oct 25 20:46:30 volumio volumio[18721]: errno: -16, Oct 25 20:46:30 volumio volumio[18721]: code: 'EBUSY', Oct 25 20:46:30 volumio volumio[18721]: syscall: 'getaddrinfo', Oct 25 20:46:30 volumio volumio[18721]: hostname: 'ws.audioscrobbler.com' Oct 25 20:46:30 volumio volumio[18721]: } Oct 25 20:46:30 volumio volumio[18721]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:31 volumio sudo[18873]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-25 20:45 Oct 25 20:46:31 volumio sudo[18873]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:31 volumio sudo[18873]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:31 volumio mpd[18842]: Oct 25 20:46 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 25 20:46:31 volumio volumio-remote-updater[662]: [2024-10-25 20:46:31] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 25 20:46:31 volumio volumio-remote-updater[662]: [2024-10-25 20:46:31] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 25 20:46:31 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 25 20:46:31 volumio sudo[18824]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:31 volumio systemd[1]: media-WD_BLACK.mount: Succeeded. Oct 25 20:46:31 volumio sudo[18806]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:31 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 25 20:46:31 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:31 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:31 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 25 20:46:31 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 103. Oct 25 20:46:31 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:31 volumio systemd[1]: Stopped Volumio Backend Module. Oct 25 20:46:31 volumio systemd[1]: Started Volumio Backend Module. Oct 25 20:46:31 volumio systemd[1]: Started Music Player Daemon. Oct 25 20:46:31 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:32 volumio volumio[18890]: info: ------------------------------------------- Oct 25 20:46:32 volumio volumio[18890]: info: ----- Volumio3 ---- Oct 25 20:46:32 volumio volumio[18890]: info: ------------------------------------------- Oct 25 20:46:32 volumio volumio[18890]: info: ----- System startup ---- Oct 25 20:46:32 volumio volumio[18890]: info: ------------------------------------------- Oct 25 20:46:32 volumio volumio[18890]: info: MYVOLUMIO Environment detected Oct 25 20:46:33 volumio volumio[18890]: info: Plugin folders cleanup Oct 25 20:46:33 volumio volumio[18890]: info: Scanning into folder /volumio/app/plugins/ Oct 25 20:46:33 volumio volumio[18890]: info: Scanning category audio_interface Oct 25 20:46:33 volumio volumio[18890]: info: Scanning category miscellanea Oct 25 20:46:33 volumio volumio[18890]: info: Scanning category music_service Oct 25 20:46:33 volumio volumio[18890]: info: Scanning category plugins.json Oct 25 20:46:33 volumio volumio[18890]: info: Scanning category system_controller Oct 25 20:46:33 volumio volumio[18890]: info: Scanning category user_interface Oct 25 20:46:33 volumio volumio[18890]: info: Scanning into folder /data/plugins/ Oct 25 20:46:33 volumio volumio[18890]: info: Scanning category music_service Oct 25 20:46:33 volumio volumio[18890]: info: Scanning category user_interface Oct 25 20:46:33 volumio volumio[18890]: info: Plugin folders cleanup completed Oct 25 20:46:33 volumio volumio[18890]: info: ------------------------------------------- Oct 25 20:46:33 volumio volumio[18890]: info: ----- Core plugins startup ---- Oct 25 20:46:33 volumio volumio[18890]: info: ------------------------------------------- Oct 25 20:46:33 volumio volumio[18890]: info: Loading plugins from folder /volumio/app/plugins/ Oct 25 20:46:33 volumio volumio[18890]: info: Adding plugin upnp to MyMusic Plugins Oct 25 20:46:33 volumio volumio[18890]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 25 20:46:33 volumio volumio[18890]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 25 20:46:33 volumio volumio[18890]: info: Loading plugins from folder /data/plugins/ Oct 25 20:46:33 volumio volumio[18890]: info: Loading plugin "system"... Oct 25 20:46:33 volumio volumio[18890]: info: Loading plugin "appearance"... Oct 25 20:46:33 volumio volumio[18890]: info: Loading plugin "network"... Oct 25 20:46:33 volumio volumio[18890]: info: Refreshing Cached IP Addresses Oct 25 20:46:33 volumio sudo[18916]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 25 20:46:33 volumio sudo[18916]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:33 volumio sudo[18916]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:33 volumio sudo[18918]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 25 20:46:33 volumio volumio[18890]: info: Loading plugin "services"... Oct 25 20:46:33 volumio sudo[18918]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:33 volumio volumio[18890]: info: Loading plugin "alsa_controller"... Oct 25 20:46:33 volumio sudo[18918]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:33 volumio sudo[18921]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 25 20:46:33 volumio sudo[18921]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:33 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:33 volumio volumio[18890]: info: Loading plugin "wizard"... Oct 25 20:46:33 volumio volumio[18890]: info: Loading plugin "networkfs"... Oct 25 20:46:33 volumio volumio[18890]: info: Starting Udev Watcher for removable devices Oct 25 20:46:33 volumio volumio[18890]: info: Ignoring mount for partition: boot Oct 25 20:46:33 volumio volumio[18890]: info: Ignoring mount for partition: volumio Oct 25 20:46:33 volumio volumio[18890]: info: Ignoring mount for partition: volumio_data Oct 25 20:46:33 volumio volumio[18890]: info: Mounting Device WD_BLACK Oct 25 20:46:33 volumio sudo[18930]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/WD_BLACK -o noatime Oct 25 20:46:33 volumio sudo[18930]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:33 volumio sudo[18930]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:33 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:33 volumio volumio[18890]: info: Loading plugin "volumio_command_line_client"... Oct 25 20:46:33 volumio volumio[18890]: info: Loading plugin "upnp"... Oct 25 20:46:33 volumio volumio[18890]: info: [1729914393981] Starting Upmpd Daemon Oct 25 20:46:33 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:33 volumio volumio[18890]: info: Loading plugin "my_music"... Oct 25 20:46:33 volumio volumio[18890]: info: Loading plugin "mpd"... Oct 25 20:46:34 volumio volumio[18890]: info: Loading plugin "upnp_browser"... Oct 25 20:46:34 volumio volumio[18890]: info: Loading plugin "alarm-clock"... Oct 25 20:46:34 volumio volumio[18890]: info: Loading plugin "airplay_emulation"... Oct 25 20:46:34 volumio volumio[18890]: info: Starting Shairport Sync Oct 25 20:46:34 volumio volumio[18890]: info: Loading plugin "last_100"... Oct 25 20:46:34 volumio volumio[18890]: info: Loading plugin "webradio"... Oct 25 20:46:34 volumio volumio[18890]: info: Loading plugin "i2s_dacs"... Oct 25 20:46:34 volumio volumio[18890]: info: Loading plugin "volumiodiscovery"... Oct 25 20:46:34 volumio volumio[18890]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:34 volumio volumio[18890]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:34 volumio node[18890]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:34 volumio volumio[18890]: *** WARNING *** For more information see Oct 25 20:46:34 volumio volumio[18890]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:34 volumio volumio[18890]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:34 volumio volumio[18890]: *** WARNING *** For more information see Oct 25 20:46:34 volumio node[18890]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:34 volumio node[18890]: *** WARNING *** For more information see Oct 25 20:46:34 volumio node[18890]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:34 volumio node[18890]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:34 volumio node[18890]: *** WARNING *** For more information see Oct 25 20:46:34 volumio volumio[18890]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 25 20:46:34 volumio volumio[18890]: info: Discovery: Started advertising with name: Volumio Oct 25 20:46:34 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:34 volumio volumio[18890]: info: Loading plugin "spop"... Oct 25 20:46:35 volumio volumio[18890]: info: Loading plugin "outputs"... Oct 25 20:46:35 volumio volumio[18890]: info: Loading plugin "albumart"... Oct 25 20:46:35 volumio volumio[18890]: info: Plugin example_plugin is not enabled Oct 25 20:46:35 volumio volumio[18890]: info: Loading plugin "inputs"... Oct 25 20:46:35 volumio volumio[18890]: info: Loading plugin "updater_comm"... Oct 25 20:46:35 volumio volumio[18890]: info: Plugin mpdemulation is not enabled Oct 25 20:46:35 volumio volumio[18890]: info: Loading plugin "rest_api"... Oct 25 20:46:35 volumio volumio[18890]: info: Loading plugin "websocket"... Oct 25 20:46:35 volumio volumio[18890]: info: Starting Socket.io Server version 2.3.0 Oct 25 20:46:35 volumio volumio[18890]: info: Loading plugin "lastfm"... Oct 25 20:46:35 volumio volumio[18890]: Forking 3 albumart workers Oct 25 20:46:35 volumio volumio[18890]: info: Loading i18n strings for locale en Oct 25 20:46:35 volumio volumio[18890]: Updating browse sources language Oct 25 20:46:35 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:35 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:35 volumio volumio[18890]: info: CoreCommandRouter::initPlayerControls Oct 25 20:46:35 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:35 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:35 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:35 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:35 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:35 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:35 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:35 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:35 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:35 volumio volumio[18890]: Express server listening on port 3000 Oct 25 20:46:35 volumio volumio[18890]: [Metrics] WebUI: 3s 581.17ms Oct 25 20:46:35 volumio volumio[18890]: info: CoreStateMachine::resetVolumioState Oct 25 20:46:35 volumio volumio[18890]: info: CoreStateMachine::getcurrentVolume Oct 25 20:46:35 volumio volumio[18890]: info: CoreCommandRouter::volumioRetrievevolume Oct 25 20:46:35 volumio volumio[18890]: info: CoreStateMachine::pushState Oct 25 20:46:35 volumio volumio[18890]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:35 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:35 volumio volumio[18890]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:36 volumio volumio[18890]: Starting albumart workers Oct 25 20:46:36 volumio volumio[18890]: Starting albumart workers Oct 25 20:46:36 volumio volumio[18890]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 25 20:46:36 volumio volumio[18890]: Starting albumart workers Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:36 volumio volumio[18890]: info: Reloading queue from file Oct 25 20:46:36 volumio volumio[18890]: info: CoreStateMachine::setRepeat false single undefined Oct 25 20:46:36 volumio volumio[18890]: info: CoreStateMachine::pushState Oct 25 20:46:36 volumio volumio[18890]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:36 volumio volumio[18890]: info: CoreStateMachine::setRandom false Oct 25 20:46:36 volumio volumio[18890]: info: CoreStateMachine::pushState Oct 25 20:46:36 volumio volumio[18890]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:36 volumio volumio[18890]: info: Setting Device type: Raspberry PI Oct 25 20:46:36 volumio volumio[18890]: info: Completed loading Core Plugins Oct 25 20:46:36 volumio volumio[18890]: info: Preparing to generate the ALSA configuration file Oct 25 20:46:36 volumio volumio[18890]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 25 20:46:36 volumio volumio[18890]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Oct 25 20:46:36 volumio volumio[18890]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 25 20:46:36 volumio volumio[18890]: info: Asound.conf file unchanged, so no further update is needed Oct 25 20:46:36 volumio volumio[18890]: info: Output device has changed, restarting MPD Oct 25 20:46:36 volumio volumio-remote-updater[662]: [2024-10-25 20:46:36] [connect] Successful connection Oct 25 20:46:36 volumio volumio[18890]: info: Output device has changed, restarting Shairport Sync Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:36 volumio sudo[18973]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:36 volumio sudo[18973]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:36 volumio sudo[18973]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:36 volumio sudo[18974]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:36 volumio sudo[18974]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:36 volumio systemd[1]: Stopping Music Player Daemon... Oct 25 20:46:36 volumio volumio[18890]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:36 volumio volumio[18890]: info: ___________ START PLUGINS ___________ Oct 25 20:46:36 volumio volumio[18890]: info: ControllerMpd::onStart: Initializing MPD Oct 25 20:46:36 volumio volumio[18890]: info: Creating MPD Configuration file Oct 25 20:46:36 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:36 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:36 volumio volumio[18890]: info: [1729914396483] CoreMusicLibrary::Adding element Media Servers Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:36 volumio sudo[18982]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:36 volumio sudo[18982]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:36 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:36 volumio sudo[18982]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:36 volumio sudo[18992]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:36 volumio sudo[18992]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:36 volumio sudo[18921]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:36 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 25 20:46:36 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:36 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:36 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:36 volumio volumio[18890]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:36 volumio volumio[18890]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:36 volumio sudo[19006]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 25 20:46:36 volumio sudo[19006]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:36 volumio volumio[18890]: info: [1729914396639] CoreMusicLibrary::Adding element Last_100 Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:36 volumio volumio[18890]: info: [1729914396643] CoreMusicLibrary::Adding element Webradio Oct 25 20:46:36 volumio sudo[19006]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:36 volumio volumio[18890]: info: Initializing BBC Radios Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:36 volumio volumio[18890]: info: Creating Spotify config file Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:36 volumio volumio[18890]: info: [1729914396731] CoreMusicLibrary::Adding element LastFM Oct 25 20:46:36 volumio volumio[18890]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:36 volumio volumio[18890]: Cannot find translation for source LastFM Oct 25 20:46:36 volumio volumio[18890]: info: [LastFM] scrobbler initiated! Oct 25 20:46:36 volumio volumio[18890]: info: [LastFM] extended logging: false Oct 25 20:46:36 volumio volumio[18890]: info: [LastFM] try scrobble stream/radio plays: true Oct 25 20:46:36 volumio volumio[18890]: info: [LastFM] Left init routine Oct 25 20:46:36 volumio volumio[18890]: info: [LastFM] Socket already connected: true Oct 25 20:46:36 volumio volumio[18890]: info: Volumio Calling Home Oct 25 20:46:36 volumio volumio[18890]: Unhandled rejection Error: No sockets available, cannot start. Oct 25 20:46:36 volumio volumio[18890]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Oct 25 20:46:36 volumio volumio[18890]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Oct 25 20:46:36 volumio volumio[18890]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Oct 25 20:46:36 volumio volumio[18890]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Oct 25 20:46:36 volumio volumio[18890]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Oct 25 20:46:36 volumio volumio[18890]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Oct 25 20:46:36 volumio volumio[18890]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Oct 25 20:46:36 volumio volumio[18890]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Oct 25 20:46:36 volumio volumio[18890]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Oct 25 20:46:36 volumio volumio[18890]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Oct 25 20:46:36 volumio volumio[18890]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Oct 25 20:46:36 volumio volumio[18890]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Oct 25 20:46:36 volumio volumio[18890]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Oct 25 20:46:36 volumio volumio[18890]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Oct 25 20:46:36 volumio volumio[18890]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Oct 25 20:46:36 volumio volumio[18890]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 25 20:46:36 volumio volumio[18890]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:36 volumio volumio[18890]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Oct 25 20:46:36 volumio volumio[18890]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Oct 25 20:46:36 volumio volumio[18890]: errno: -16, Oct 25 20:46:36 volumio volumio[18890]: code: 'EBUSY', Oct 25 20:46:36 volumio volumio[18890]: syscall: 'getaddrinfo', Oct 25 20:46:36 volumio volumio[18890]: hostname: 'ws.audioscrobbler.com' Oct 25 20:46:36 volumio volumio[18890]: } Oct 25 20:46:36 volumio volumio[18890]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:37 volumio sudo[19042]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-25 20:45 Oct 25 20:46:37 volumio sudo[19042]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:37 volumio sudo[19042]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:37 volumio mpd[19019]: Oct 25 20:46 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 25 20:46:37 volumio volumio-remote-updater[662]: [2024-10-25 20:46:37] [info] asio async_read_at_least error: system:104 (Connection reset by peer) Oct 25 20:46:37 volumio volumio-remote-updater[662]: [2024-10-25 20:46:37] [error] handle_read_http_response error: websocketpp.transport:2 (Underlying Transport Error) Oct 25 20:46:37 volumio volumio-remote-updater[662]: [2024-10-25 20:46:37] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Oct 25 20:46:37 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 25 20:46:37 volumio systemd[1]: media-WD_BLACK.mount: Succeeded. Oct 25 20:46:37 volumio sudo[18974]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:37 volumio sudo[18992]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:37 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 25 20:46:37 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:37 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:37 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 25 20:46:37 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 104. Oct 25 20:46:37 volumio systemd[1]: Started Music Player Daemon. Oct 25 20:46:37 volumio systemd[1]: Stopped Volumio Backend Module. Oct 25 20:46:37 volumio systemd[1]: Started Volumio Backend Module. Oct 25 20:46:37 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:37 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:38 volumio volumio[19058]: info: ------------------------------------------- Oct 25 20:46:38 volumio volumio[19058]: info: ----- Volumio3 ---- Oct 25 20:46:38 volumio volumio[19058]: info: ------------------------------------------- Oct 25 20:46:38 volumio volumio[19058]: info: ----- System startup ---- Oct 25 20:46:38 volumio volumio[19058]: info: ------------------------------------------- Oct 25 20:46:39 volumio volumio[19058]: info: MYVOLUMIO Environment detected Oct 25 20:46:39 volumio volumio[19058]: info: Plugin folders cleanup Oct 25 20:46:39 volumio volumio[19058]: info: Scanning into folder /volumio/app/plugins/ Oct 25 20:46:39 volumio volumio[19058]: info: Scanning category audio_interface Oct 25 20:46:39 volumio volumio[19058]: info: Scanning category miscellanea Oct 25 20:46:39 volumio volumio[19058]: info: Scanning category music_service Oct 25 20:46:39 volumio volumio[19058]: info: Scanning category plugins.json Oct 25 20:46:39 volumio volumio[19058]: info: Scanning category system_controller Oct 25 20:46:39 volumio volumio[19058]: info: Scanning category user_interface Oct 25 20:46:39 volumio volumio[19058]: info: Scanning into folder /data/plugins/ Oct 25 20:46:39 volumio volumio[19058]: info: Scanning category music_service Oct 25 20:46:39 volumio volumio[19058]: info: Scanning category user_interface Oct 25 20:46:39 volumio volumio[19058]: info: Plugin folders cleanup completed Oct 25 20:46:39 volumio volumio[19058]: info: ------------------------------------------- Oct 25 20:46:39 volumio volumio[19058]: info: ----- Core plugins startup ---- Oct 25 20:46:39 volumio volumio[19058]: info: ------------------------------------------- Oct 25 20:46:39 volumio volumio[19058]: info: Loading plugins from folder /volumio/app/plugins/ Oct 25 20:46:39 volumio volumio[19058]: info: Adding plugin upnp to MyMusic Plugins Oct 25 20:46:39 volumio volumio[19058]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 25 20:46:39 volumio volumio[19058]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 25 20:46:39 volumio volumio[19058]: info: Loading plugins from folder /data/plugins/ Oct 25 20:46:39 volumio volumio[19058]: info: Loading plugin "system"... Oct 25 20:46:39 volumio volumio[19058]: info: Loading plugin "appearance"... Oct 25 20:46:39 volumio volumio[19058]: info: Loading plugin "network"... Oct 25 20:46:39 volumio volumio[19058]: info: Refreshing Cached IP Addresses Oct 25 20:46:39 volumio sudo[19085]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 25 20:46:39 volumio sudo[19085]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:39 volumio sudo[19085]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:39 volumio sudo[19087]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 25 20:46:39 volumio sudo[19087]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:39 volumio volumio[19058]: info: Loading plugin "services"... Oct 25 20:46:39 volumio volumio[19058]: info: Loading plugin "alsa_controller"... Oct 25 20:46:39 volumio sudo[19087]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:39 volumio sudo[19090]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 25 20:46:39 volumio sudo[19090]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:39 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:39 volumio volumio[19058]: info: Loading plugin "wizard"... Oct 25 20:46:39 volumio volumio[19058]: info: Loading plugin "networkfs"... Oct 25 20:46:39 volumio volumio[19058]: info: Starting Udev Watcher for removable devices Oct 25 20:46:39 volumio volumio[19058]: info: Ignoring mount for partition: boot Oct 25 20:46:39 volumio volumio[19058]: info: Ignoring mount for partition: volumio Oct 25 20:46:39 volumio volumio[19058]: info: Ignoring mount for partition: volumio_data Oct 25 20:46:39 volumio volumio[19058]: info: Mounting Device WD_BLACK Oct 25 20:46:39 volumio sudo[19099]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/WD_BLACK -o noatime Oct 25 20:46:39 volumio sudo[19099]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:40 volumio sudo[19099]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:40 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:40 volumio volumio[19058]: info: Loading plugin "volumio_command_line_client"... Oct 25 20:46:40 volumio volumio[19058]: info: Loading plugin "upnp"... Oct 25 20:46:40 volumio volumio[19058]: info: [1729914400195] Starting Upmpd Daemon Oct 25 20:46:40 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:40 volumio volumio[19058]: info: Loading plugin "my_music"... Oct 25 20:46:40 volumio volumio[19058]: info: Loading plugin "mpd"... Oct 25 20:46:40 volumio volumio[19058]: info: Loading plugin "upnp_browser"... Oct 25 20:46:40 volumio volumio[19058]: info: Loading plugin "alarm-clock"... Oct 25 20:46:40 volumio volumio[19058]: info: Loading plugin "airplay_emulation"... Oct 25 20:46:40 volumio volumio[19058]: info: Starting Shairport Sync Oct 25 20:46:40 volumio volumio[19058]: info: Loading plugin "last_100"... Oct 25 20:46:40 volumio volumio[19058]: info: Loading plugin "webradio"... Oct 25 20:46:40 volumio volumio[19058]: info: Loading plugin "i2s_dacs"... Oct 25 20:46:40 volumio volumio[19058]: info: Loading plugin "volumiodiscovery"... Oct 25 20:46:40 volumio volumio[19058]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:40 volumio node[19058]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:40 volumio volumio[19058]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:40 volumio node[19058]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:40 volumio volumio[19058]: *** WARNING *** For more information see Oct 25 20:46:40 volumio node[19058]: *** WARNING *** For more information see Oct 25 20:46:40 volumio volumio[19058]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:40 volumio node[19058]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:40 volumio volumio[19058]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:40 volumio node[19058]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:40 volumio volumio[19058]: *** WARNING *** For more information see Oct 25 20:46:40 volumio node[19058]: *** WARNING *** For more information see Oct 25 20:46:40 volumio volumio[19058]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 25 20:46:40 volumio volumio[19058]: info: Discovery: Started advertising with name: Volumio Oct 25 20:46:40 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:40 volumio volumio[19058]: info: Loading plugin "spop"... Oct 25 20:46:41 volumio volumio[19058]: info: Loading plugin "outputs"... Oct 25 20:46:41 volumio volumio[19058]: info: Loading plugin "albumart"... Oct 25 20:46:41 volumio volumio[19058]: info: Plugin example_plugin is not enabled Oct 25 20:46:41 volumio volumio[19058]: info: Loading plugin "inputs"... Oct 25 20:46:41 volumio volumio[19058]: info: Loading plugin "updater_comm"... Oct 25 20:46:41 volumio volumio[19058]: info: Plugin mpdemulation is not enabled Oct 25 20:46:41 volumio volumio[19058]: info: Loading plugin "rest_api"... Oct 25 20:46:41 volumio volumio[19058]: info: Loading plugin "websocket"... Oct 25 20:46:41 volumio volumio[19058]: info: Starting Socket.io Server version 2.3.0 Oct 25 20:46:41 volumio volumio[19058]: info: Loading plugin "lastfm"... Oct 25 20:46:41 volumio volumio[19058]: Forking 3 albumart workers Oct 25 20:46:41 volumio volumio[19058]: info: Loading i18n strings for locale en Oct 25 20:46:41 volumio volumio[19058]: Updating browse sources language Oct 25 20:46:41 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::initPlayerControls Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: Express server listening on port 3000 Oct 25 20:46:42 volumio volumio[19058]: [Metrics] WebUI: 3s 624.59ms Oct 25 20:46:42 volumio volumio[19058]: info: CoreStateMachine::resetVolumioState Oct 25 20:46:42 volumio volumio[19058]: info: CoreStateMachine::getcurrentVolume Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::volumioRetrievevolume Oct 25 20:46:42 volumio volumio[19058]: info: CoreStateMachine::pushState Oct 25 20:46:42 volumio volumio[19058]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:42 volumio volumio[19058]: Starting albumart workers Oct 25 20:46:42 volumio volumio[19058]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 25 20:46:42 volumio volumio[19058]: Starting albumart workers Oct 25 20:46:42 volumio volumio[19058]: Starting albumart workers Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: Reloading queue from file Oct 25 20:46:42 volumio volumio[19058]: info: CoreStateMachine::setRepeat false single undefined Oct 25 20:46:42 volumio volumio[19058]: info: CoreStateMachine::pushState Oct 25 20:46:42 volumio volumio[19058]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:42 volumio volumio[19058]: info: CoreStateMachine::setRandom false Oct 25 20:46:42 volumio volumio[19058]: info: CoreStateMachine::pushState Oct 25 20:46:42 volumio volumio[19058]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:42 volumio volumio[19058]: info: Setting Device type: Raspberry PI Oct 25 20:46:42 volumio volumio[19058]: info: Completed loading Core Plugins Oct 25 20:46:42 volumio volumio[19058]: info: Preparing to generate the ALSA configuration file Oct 25 20:46:42 volumio volumio[19058]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 25 20:46:42 volumio volumio[19058]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Oct 25 20:46:42 volumio volumio[19058]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 25 20:46:42 volumio volumio[19058]: info: Asound.conf file unchanged, so no further update is needed Oct 25 20:46:42 volumio volumio[19058]: info: Output device has changed, restarting MPD Oct 25 20:46:42 volumio sudo[19146]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:42 volumio sudo[19146]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:42 volumio volumio[19058]: info: Output device has changed, restarting Shairport Sync Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:42 volumio sudo[19146]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:42 volumio sudo[19155]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:42 volumio sudo[19155]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:42 volumio systemd[1]: Stopping Music Player Daemon... Oct 25 20:46:42 volumio volumio[19058]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:42 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:42 volumio volumio[19058]: info: ___________ START PLUGINS ___________ Oct 25 20:46:42 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:42 volumio volumio[19058]: info: ControllerMpd::onStart: Initializing MPD Oct 25 20:46:42 volumio volumio[19058]: info: Creating MPD Configuration file Oct 25 20:46:42 volumio sudo[19090]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:42 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:42 volumio sudo[19175]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:42 volumio sudo[19175]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:42 volumio volumio[19058]: info: [1729914402772] CoreMusicLibrary::Adding element Media Servers Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:42 volumio sudo[19175]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:42 volumio sudo[19178]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:42 volumio sudo[19178]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:42 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 25 20:46:42 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:42 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:42 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:42 volumio volumio[19058]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:42 volumio volumio[19058]: info: [1729914402876] CoreMusicLibrary::Adding element Last_100 Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:42 volumio volumio[19058]: info: [1729914402878] CoreMusicLibrary::Adding element Webradio Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:42 volumio volumio[19058]: info: Initializing BBC Radios Oct 25 20:46:42 volumio sudo[19183]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 25 20:46:42 volumio sudo[19183]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:42 volumio sudo[19183]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: Creating Spotify config file Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:42 volumio volumio[19058]: info: [1729914402953] CoreMusicLibrary::Adding element LastFM Oct 25 20:46:42 volumio volumio[19058]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:42 volumio volumio[19058]: Cannot find translation for source LastFM Oct 25 20:46:42 volumio volumio[19058]: info: [LastFM] scrobbler initiated! Oct 25 20:46:42 volumio volumio[19058]: info: [LastFM] extended logging: false Oct 25 20:46:42 volumio volumio[19058]: info: [LastFM] try scrobble stream/radio plays: true Oct 25 20:46:42 volumio volumio[19058]: info: [LastFM] Left init routine Oct 25 20:46:42 volumio volumio[19058]: info: [LastFM] Socket already connected: true Oct 25 20:46:42 volumio volumio[19058]: info: Volumio Calling Home Oct 25 20:46:43 volumio volumio[19058]: Unhandled rejection Error: No sockets available, cannot start. Oct 25 20:46:43 volumio volumio[19058]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Oct 25 20:46:43 volumio volumio[19058]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Oct 25 20:46:43 volumio volumio[19058]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Oct 25 20:46:43 volumio volumio[19058]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Oct 25 20:46:43 volumio volumio[19058]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Oct 25 20:46:43 volumio volumio[19058]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Oct 25 20:46:43 volumio volumio[19058]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Oct 25 20:46:43 volumio volumio[19058]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Oct 25 20:46:43 volumio volumio[19058]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Oct 25 20:46:43 volumio volumio[19058]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Oct 25 20:46:43 volumio volumio[19058]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Oct 25 20:46:43 volumio volumio[19058]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Oct 25 20:46:43 volumio volumio[19058]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Oct 25 20:46:43 volumio volumio[19058]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Oct 25 20:46:43 volumio volumio[19058]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Oct 25 20:46:43 volumio volumio[19058]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 25 20:46:43 volumio volumio[19058]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:43 volumio volumio[19058]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Oct 25 20:46:43 volumio volumio[19058]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Oct 25 20:46:43 volumio volumio[19058]: errno: -16, Oct 25 20:46:43 volumio volumio[19058]: code: 'EBUSY', Oct 25 20:46:43 volumio volumio[19058]: syscall: 'getaddrinfo', Oct 25 20:46:43 volumio volumio[19058]: hostname: 'ws.audioscrobbler.com' Oct 25 20:46:43 volumio volumio[19058]: } Oct 25 20:46:43 volumio volumio[19058]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:43 volumio sudo[19211]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-25 20:45 Oct 25 20:46:43 volumio sudo[19211]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:43 volumio sudo[19211]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:43 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 25 20:46:43 volumio sudo[19155]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:43 volumio systemd[1]: media-WD_BLACK.mount: Succeeded. Oct 25 20:46:43 volumio sudo[19178]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:43 volumio mpd[19190]: Oct 25 20:46 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 25 20:46:43 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 25 20:46:43 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:43 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:44 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 25 20:46:44 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 105. Oct 25 20:46:44 volumio systemd[1]: Started Music Player Daemon. Oct 25 20:46:44 volumio systemd[1]: Stopped Volumio Backend Module. Oct 25 20:46:44 volumio systemd[1]: Started Volumio Backend Module. Oct 25 20:46:44 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:44 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:44 volumio volumio-remote-updater[662]: [2024-10-25 20:46:44] [connect] Successful connection Oct 25 20:46:45 volumio volumio[19227]: info: ------------------------------------------- Oct 25 20:46:45 volumio volumio[19227]: info: ----- Volumio3 ---- Oct 25 20:46:45 volumio volumio[19227]: info: ------------------------------------------- Oct 25 20:46:45 volumio volumio[19227]: info: ----- System startup ---- Oct 25 20:46:45 volumio volumio[19227]: info: ------------------------------------------- Oct 25 20:46:45 volumio volumio[19227]: info: MYVOLUMIO Environment detected Oct 25 20:46:45 volumio volumio[19227]: info: Plugin folders cleanup Oct 25 20:46:45 volumio volumio[19227]: info: Scanning into folder /volumio/app/plugins/ Oct 25 20:46:45 volumio volumio[19227]: info: Scanning category audio_interface Oct 25 20:46:45 volumio volumio[19227]: info: Scanning category miscellanea Oct 25 20:46:45 volumio volumio[19227]: info: Scanning category music_service Oct 25 20:46:45 volumio volumio[19227]: info: Scanning category plugins.json Oct 25 20:46:45 volumio volumio[19227]: info: Scanning category system_controller Oct 25 20:46:45 volumio volumio[19227]: info: Scanning category user_interface Oct 25 20:46:45 volumio volumio[19227]: info: Scanning into folder /data/plugins/ Oct 25 20:46:45 volumio volumio[19227]: info: Scanning category music_service Oct 25 20:46:45 volumio volumio[19227]: info: Scanning category user_interface Oct 25 20:46:45 volumio volumio[19227]: info: Plugin folders cleanup completed Oct 25 20:46:45 volumio volumio[19227]: info: ------------------------------------------- Oct 25 20:46:45 volumio volumio[19227]: info: ----- Core plugins startup ---- Oct 25 20:46:45 volumio volumio[19227]: info: ------------------------------------------- Oct 25 20:46:45 volumio volumio[19227]: info: Loading plugins from folder /volumio/app/plugins/ Oct 25 20:46:45 volumio volumio[19227]: info: Adding plugin upnp to MyMusic Plugins Oct 25 20:46:45 volumio volumio[19227]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 25 20:46:45 volumio volumio[19227]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 25 20:46:45 volumio volumio[19227]: info: Loading plugins from folder /data/plugins/ Oct 25 20:46:45 volumio volumio[19227]: info: Loading plugin "system"... Oct 25 20:46:45 volumio volumio[19227]: info: Loading plugin "appearance"... Oct 25 20:46:46 volumio volumio[19227]: info: Loading plugin "network"... Oct 25 20:46:46 volumio volumio[19227]: info: Refreshing Cached IP Addresses Oct 25 20:46:46 volumio sudo[19254]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 25 20:46:46 volumio sudo[19254]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:46 volumio sudo[19254]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:46 volumio sudo[19256]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 25 20:46:46 volumio volumio[19227]: info: Loading plugin "services"... Oct 25 20:46:46 volumio sudo[19256]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:46 volumio volumio[19227]: info: Loading plugin "alsa_controller"... Oct 25 20:46:46 volumio sudo[19256]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:46 volumio sudo[19259]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 25 20:46:46 volumio sudo[19259]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:46 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:46 volumio volumio[19227]: info: Loading plugin "wizard"... Oct 25 20:46:46 volumio volumio[19227]: info: Loading plugin "networkfs"... Oct 25 20:46:46 volumio volumio[19227]: info: Starting Udev Watcher for removable devices Oct 25 20:46:46 volumio volumio[19227]: info: Ignoring mount for partition: boot Oct 25 20:46:46 volumio volumio[19227]: info: Ignoring mount for partition: volumio Oct 25 20:46:46 volumio volumio[19227]: info: Ignoring mount for partition: volumio_data Oct 25 20:46:46 volumio volumio[19227]: info: Mounting Device WD_BLACK Oct 25 20:46:46 volumio sudo[19268]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/WD_BLACK -o noatime Oct 25 20:46:46 volumio sudo[19268]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:46 volumio sudo[19268]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:46 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:46 volumio volumio[19227]: info: Loading plugin "volumio_command_line_client"... Oct 25 20:46:46 volumio volumio[19227]: info: Loading plugin "upnp"... Oct 25 20:46:46 volumio volumio[19227]: info: [1729914406515] Starting Upmpd Daemon Oct 25 20:46:46 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:46 volumio volumio[19227]: info: Loading plugin "my_music"... Oct 25 20:46:46 volumio volumio[19227]: info: Loading plugin "mpd"... Oct 25 20:46:46 volumio volumio[19227]: info: Loading plugin "upnp_browser"... Oct 25 20:46:46 volumio volumio[19227]: info: Loading plugin "alarm-clock"... Oct 25 20:46:46 volumio volumio[19227]: info: Loading plugin "airplay_emulation"... Oct 25 20:46:46 volumio volumio[19227]: info: Starting Shairport Sync Oct 25 20:46:46 volumio volumio[19227]: info: Loading plugin "last_100"... Oct 25 20:46:46 volumio volumio[19227]: info: Loading plugin "webradio"... Oct 25 20:46:47 volumio volumio[19227]: info: Loading plugin "i2s_dacs"... Oct 25 20:46:47 volumio volumio[19227]: info: Loading plugin "volumiodiscovery"... Oct 25 20:46:47 volumio volumio[19227]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:47 volumio volumio[19227]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:47 volumio node[19227]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:47 volumio volumio[19227]: *** WARNING *** For more information see Oct 25 20:46:47 volumio volumio[19227]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:47 volumio volumio[19227]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:47 volumio volumio[19227]: *** WARNING *** For more information see Oct 25 20:46:47 volumio node[19227]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:47 volumio node[19227]: *** WARNING *** For more information see Oct 25 20:46:47 volumio node[19227]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:47 volumio node[19227]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:47 volumio node[19227]: *** WARNING *** For more information see Oct 25 20:46:47 volumio volumio[19227]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 25 20:46:47 volumio volumio[19227]: info: Discovery: Started advertising with name: Volumio Oct 25 20:46:47 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:47 volumio volumio[19227]: info: Loading plugin "spop"... Oct 25 20:46:47 volumio volumio[19227]: info: Loading plugin "outputs"... Oct 25 20:46:47 volumio volumio[19227]: info: Loading plugin "albumart"... Oct 25 20:46:47 volumio volumio[19227]: info: Plugin example_plugin is not enabled Oct 25 20:46:47 volumio volumio[19227]: info: Loading plugin "inputs"... Oct 25 20:46:47 volumio volumio[19227]: info: Loading plugin "updater_comm"... Oct 25 20:46:47 volumio volumio[19227]: info: Plugin mpdemulation is not enabled Oct 25 20:46:47 volumio volumio[19227]: info: Loading plugin "rest_api"... Oct 25 20:46:47 volumio volumio[19227]: info: Loading plugin "websocket"... Oct 25 20:46:47 volumio volumio[19227]: info: Starting Socket.io Server version 2.3.0 Oct 25 20:46:47 volumio volumio[19227]: info: Loading plugin "lastfm"... Oct 25 20:46:47 volumio volumio[19227]: Forking 3 albumart workers Oct 25 20:46:48 volumio volumio[19227]: info: Loading i18n strings for locale en Oct 25 20:46:48 volumio volumio[19227]: Updating browse sources language Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::initPlayerControls Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:48 volumio volumio[19227]: Express server listening on port 3000 Oct 25 20:46:48 volumio volumio[19227]: [Metrics] WebUI: 3s 571.80ms Oct 25 20:46:48 volumio volumio[19227]: info: CoreStateMachine::resetVolumioState Oct 25 20:46:48 volumio volumio[19227]: info: CoreStateMachine::getcurrentVolume Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::volumioRetrievevolume Oct 25 20:46:48 volumio volumio[19227]: info: CoreStateMachine::pushState Oct 25 20:46:48 volumio volumio[19227]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:48 volumio volumio-remote-updater[662]: [2024-10-25 20:46:48] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1729914404 101 Oct 25 20:46:48 volumio volumio[19227]: 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: 1 Oct 25 20:46:48 volumio volumio[19227]: Starting albumart workers Oct 25 20:46:48 volumio volumio[19227]: Starting albumart workers Oct 25 20:46:48 volumio volumio[19227]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Oct 25 20:46:48 volumio volumio[19227]: Starting albumart workers Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:48 volumio volumio[19227]: info: Reloading queue from file Oct 25 20:46:48 volumio volumio[19227]: info: CoreStateMachine::setRepeat false single undefined Oct 25 20:46:48 volumio volumio[19227]: info: CoreStateMachine::pushState Oct 25 20:46:48 volumio volumio[19227]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:48 volumio volumio[19227]: info: CoreStateMachine::setRandom false Oct 25 20:46:48 volumio volumio[19227]: info: CoreStateMachine::pushState Oct 25 20:46:48 volumio volumio[19227]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:48 volumio volumio[19227]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 25 20:46:48 volumio volumio[19227]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Oct 25 20:46:48 volumio volumio[19227]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 25 20:46:48 volumio volumio[19227]: info: Setting Device type: Raspberry PI Oct 25 20:46:48 volumio volumio[19227]: info: Completed loading Core Plugins Oct 25 20:46:48 volumio volumio[19227]: info: Preparing to generate the ALSA configuration file Oct 25 20:46:48 volumio volumio[19227]: info: Asound.conf file unchanged, so no further update is needed Oct 25 20:46:48 volumio volumio[19227]: info: Output device has changed, restarting MPD Oct 25 20:46:48 volumio volumio[19227]: info: Output device has changed, restarting Shairport Sync Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:48 volumio sudo[19311]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:48 volumio sudo[19311]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:48 volumio sudo[19312]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:48 volumio sudo[19312]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:48 volumio sudo[19311]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:48 volumio volumio[19227]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:48 volumio systemd[1]: Stopping Music Player Daemon... Oct 25 20:46:48 volumio volumio[19227]: info: ___________ START PLUGINS ___________ Oct 25 20:46:48 volumio volumio[19227]: info: ControllerMpd::onStart: Initializing MPD Oct 25 20:46:48 volumio volumio[19227]: info: Creating MPD Configuration file Oct 25 20:46:48 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:48 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:48 volumio volumio[19227]: info: [1729914408976] CoreMusicLibrary::Adding element Media Servers Oct 25 20:46:48 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:48 volumio sudo[19320]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:48 volumio sudo[19320]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:48 volumio sudo[19322]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:49 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:48 volumio sudo[19322]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:49 volumio sudo[19320]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:49 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:49 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:49 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 25 20:46:49 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:49 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:49 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:49 volumio sudo[19259]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:49 volumio volumio[19227]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:49 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:49 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:49 volumio sudo[19325]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 25 20:46:49 volumio sudo[19325]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:49 volumio sudo[19325]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:49 volumio volumio[19227]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:49 volumio volumio[19227]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:49 volumio volumio[19227]: info: [1729914409183] CoreMusicLibrary::Adding element Last_100 Oct 25 20:46:49 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:49 volumio volumio[19227]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:49 volumio volumio[19227]: info: [1729914409187] CoreMusicLibrary::Adding element Webradio Oct 25 20:46:49 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:49 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:49 volumio volumio[19227]: info: Initializing BBC Radios Oct 25 20:46:49 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:49 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:49 volumio volumio[19227]: info: Creating Spotify config file Oct 25 20:46:49 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:49 volumio volumio[19227]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:49 volumio volumio[19227]: info: [1729914409270] CoreMusicLibrary::Adding element LastFM Oct 25 20:46:49 volumio volumio[19227]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:49 volumio volumio[19227]: Cannot find translation for source LastFM Oct 25 20:46:49 volumio volumio[19227]: info: [LastFM] scrobbler initiated! Oct 25 20:46:49 volumio volumio[19227]: info: [LastFM] extended logging: false Oct 25 20:46:49 volumio volumio[19227]: info: [LastFM] try scrobble stream/radio plays: true Oct 25 20:46:49 volumio volumio[19227]: info: [LastFM] Left init routine Oct 25 20:46:49 volumio volumio[19227]: info: [LastFM] Socket already connected: true Oct 25 20:46:49 volumio volumio[19227]: info: Volumio Calling Home Oct 25 20:46:49 volumio volumio[19227]: Unhandled rejection Error: No sockets available, cannot start. Oct 25 20:46:49 volumio volumio[19227]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Oct 25 20:46:49 volumio volumio[19227]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Oct 25 20:46:49 volumio volumio[19227]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Oct 25 20:46:49 volumio volumio[19227]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Oct 25 20:46:49 volumio volumio[19227]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Oct 25 20:46:49 volumio volumio[19227]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Oct 25 20:46:49 volumio volumio[19227]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Oct 25 20:46:49 volumio volumio[19227]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Oct 25 20:46:49 volumio volumio[19227]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Oct 25 20:46:49 volumio volumio[19227]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Oct 25 20:46:49 volumio volumio[19227]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Oct 25 20:46:49 volumio volumio[19227]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Oct 25 20:46:49 volumio volumio[19227]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Oct 25 20:46:49 volumio volumio[19227]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Oct 25 20:46:49 volumio volumio[19227]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Oct 25 20:46:49 volumio volumio[19227]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 25 20:46:49 volumio volumio[19227]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:49 volumio volumio[19227]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Oct 25 20:46:49 volumio volumio[19227]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Oct 25 20:46:49 volumio volumio[19227]: errno: -16, Oct 25 20:46:49 volumio volumio[19227]: code: 'EBUSY', Oct 25 20:46:49 volumio volumio[19227]: syscall: 'getaddrinfo', Oct 25 20:46:49 volumio volumio[19227]: hostname: 'ws.audioscrobbler.com' Oct 25 20:46:49 volumio volumio[19227]: } Oct 25 20:46:49 volumio volumio[19227]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:49 volumio sudo[19380]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-25 20:45 Oct 25 20:46:49 volumio sudo[19380]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:49 volumio mpd[19355]: Oct 25 20:46 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 25 20:46:49 volumio sudo[19380]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:50 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 25 20:46:50 volumio volumio-remote-updater[662]: [2024-10-25 20:46:50] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Oct 25 20:46:50 volumio volumio-remote-updater[662]: [2024-10-25 20:46:50] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Oct 25 20:46:50 volumio sudo[19312]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:50 volumio sudo[19322]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:50 volumio systemd[1]: media-WD_BLACK.mount: Succeeded. Oct 25 20:46:50 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 25 20:46:50 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:50 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:50 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 25 20:46:50 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 106. Oct 25 20:46:50 volumio systemd[1]: Started Music Player Daemon. Oct 25 20:46:50 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:50 volumio systemd[1]: Stopped Volumio Backend Module. Oct 25 20:46:50 volumio systemd[1]: Started Volumio Backend Module. Oct 25 20:46:50 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:51 volumio volumio[19396]: info: ------------------------------------------- Oct 25 20:46:51 volumio volumio[19396]: info: ----- Volumio3 ---- Oct 25 20:46:51 volumio volumio[19396]: info: ------------------------------------------- Oct 25 20:46:51 volumio volumio[19396]: info: ----- System startup ---- Oct 25 20:46:51 volumio volumio[19396]: info: ------------------------------------------- Oct 25 20:46:51 volumio volumio[19396]: info: MYVOLUMIO Environment detected Oct 25 20:46:51 volumio volumio[19396]: info: Plugin folders cleanup Oct 25 20:46:51 volumio volumio[19396]: info: Scanning into folder /volumio/app/plugins/ Oct 25 20:46:51 volumio volumio[19396]: info: Scanning category audio_interface Oct 25 20:46:51 volumio volumio[19396]: info: Scanning category miscellanea Oct 25 20:46:51 volumio volumio[19396]: info: Scanning category music_service Oct 25 20:46:51 volumio volumio[19396]: info: Scanning category plugins.json Oct 25 20:46:51 volumio volumio[19396]: info: Scanning category system_controller Oct 25 20:46:51 volumio volumio[19396]: info: Scanning category user_interface Oct 25 20:46:51 volumio volumio[19396]: info: Scanning into folder /data/plugins/ Oct 25 20:46:51 volumio volumio[19396]: info: Scanning category music_service Oct 25 20:46:51 volumio volumio[19396]: info: Scanning category user_interface Oct 25 20:46:51 volumio volumio[19396]: info: Plugin folders cleanup completed Oct 25 20:46:51 volumio volumio[19396]: info: ------------------------------------------- Oct 25 20:46:51 volumio volumio[19396]: info: ----- Core plugins startup ---- Oct 25 20:46:51 volumio volumio[19396]: info: ------------------------------------------- Oct 25 20:46:51 volumio volumio[19396]: info: Loading plugins from folder /volumio/app/plugins/ Oct 25 20:46:51 volumio volumio[19396]: info: Adding plugin upnp to MyMusic Plugins Oct 25 20:46:51 volumio volumio[19396]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 25 20:46:51 volumio volumio[19396]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 25 20:46:51 volumio volumio[19396]: info: Loading plugins from folder /data/plugins/ Oct 25 20:46:51 volumio volumio[19396]: info: Loading plugin "system"... Oct 25 20:46:51 volumio volumio[19396]: info: Loading plugin "appearance"... Oct 25 20:46:52 volumio volumio[19396]: info: Loading plugin "network"... Oct 25 20:46:52 volumio volumio[19396]: info: Refreshing Cached IP Addresses Oct 25 20:46:52 volumio sudo[19422]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 25 20:46:52 volumio sudo[19422]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:52 volumio sudo[19422]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:52 volumio sudo[19424]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 25 20:46:52 volumio sudo[19424]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:52 volumio volumio[19396]: info: Loading plugin "services"... Oct 25 20:46:52 volumio sudo[19424]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:52 volumio volumio[19396]: info: Loading plugin "alsa_controller"... Oct 25 20:46:52 volumio sudo[19427]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 25 20:46:52 volumio sudo[19427]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:52 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:52 volumio volumio[19396]: info: Loading plugin "wizard"... Oct 25 20:46:52 volumio volumio[19396]: info: Loading plugin "networkfs"... Oct 25 20:46:52 volumio volumio[19396]: info: Starting Udev Watcher for removable devices Oct 25 20:46:52 volumio volumio[19396]: info: Ignoring mount for partition: boot Oct 25 20:46:52 volumio volumio[19396]: info: Ignoring mount for partition: volumio Oct 25 20:46:52 volumio volumio[19396]: info: Ignoring mount for partition: volumio_data Oct 25 20:46:52 volumio volumio[19396]: info: Mounting Device WD_BLACK Oct 25 20:46:52 volumio sudo[19436]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/WD_BLACK -o noatime Oct 25 20:46:52 volumio sudo[19436]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:52 volumio sudo[19436]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:52 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:52 volumio volumio[19396]: info: Loading plugin "volumio_command_line_client"... Oct 25 20:46:52 volumio volumio[19396]: info: Loading plugin "upnp"... Oct 25 20:46:52 volumio volumio[19396]: info: [1729914412697] Starting Upmpd Daemon Oct 25 20:46:52 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:52 volumio volumio[19396]: info: Loading plugin "my_music"... Oct 25 20:46:52 volumio volumio[19396]: info: Loading plugin "mpd"... Oct 25 20:46:52 volumio volumio[19396]: info: Loading plugin "upnp_browser"... Oct 25 20:46:53 volumio volumio[19396]: info: Loading plugin "alarm-clock"... Oct 25 20:46:53 volumio volumio[19396]: info: Loading plugin "airplay_emulation"... Oct 25 20:46:53 volumio volumio[19396]: info: Starting Shairport Sync Oct 25 20:46:53 volumio volumio[19396]: info: Loading plugin "last_100"... Oct 25 20:46:53 volumio volumio[19396]: info: Loading plugin "webradio"... Oct 25 20:46:53 volumio volumio[19396]: info: Loading plugin "i2s_dacs"... Oct 25 20:46:53 volumio volumio[19396]: info: Loading plugin "volumiodiscovery"... Oct 25 20:46:53 volumio volumio[19396]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:53 volumio node[19396]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:53 volumio volumio[19396]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:53 volumio node[19396]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:53 volumio volumio[19396]: *** WARNING *** For more information see Oct 25 20:46:53 volumio node[19396]: *** WARNING *** For more information see Oct 25 20:46:53 volumio volumio[19396]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:53 volumio node[19396]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:53 volumio volumio[19396]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:53 volumio node[19396]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:53 volumio volumio[19396]: *** WARNING *** For more information see Oct 25 20:46:53 volumio node[19396]: *** WARNING *** For more information see Oct 25 20:46:53 volumio volumio[19396]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 25 20:46:53 volumio volumio[19396]: info: Discovery: Started advertising with name: Volumio Oct 25 20:46:53 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:53 volumio volumio[19396]: info: Loading plugin "spop"... Oct 25 20:46:53 volumio volumio[19396]: info: Loading plugin "outputs"... Oct 25 20:46:53 volumio volumio[19396]: info: Loading plugin "albumart"... Oct 25 20:46:53 volumio volumio[19396]: info: Plugin example_plugin is not enabled Oct 25 20:46:53 volumio volumio[19396]: info: Loading plugin "inputs"... Oct 25 20:46:53 volumio volumio[19396]: info: Loading plugin "updater_comm"... Oct 25 20:46:54 volumio volumio[19396]: info: Plugin mpdemulation is not enabled Oct 25 20:46:54 volumio volumio[19396]: info: Loading plugin "rest_api"... Oct 25 20:46:54 volumio volumio[19396]: info: Loading plugin "websocket"... Oct 25 20:46:54 volumio volumio[19396]: info: Starting Socket.io Server version 2.3.0 Oct 25 20:46:54 volumio volumio[19396]: info: Loading plugin "lastfm"... Oct 25 20:46:54 volumio volumio[19396]: Forking 3 albumart workers Oct 25 20:46:54 volumio volumio[19396]: info: Loading i18n strings for locale en Oct 25 20:46:54 volumio volumio[19396]: Updating browse sources language Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::initPlayerControls Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:54 volumio volumio[19396]: Express server listening on port 3000 Oct 25 20:46:54 volumio volumio[19396]: [Metrics] WebUI: 3s 581.21ms Oct 25 20:46:54 volumio volumio[19396]: info: CoreStateMachine::resetVolumioState Oct 25 20:46:54 volumio volumio[19396]: info: CoreStateMachine::getcurrentVolume Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::volumioRetrievevolume Oct 25 20:46:54 volumio volumio[19396]: info: CoreStateMachine::pushState Oct 25 20:46:54 volumio volumio[19396]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:54 volumio volumio[19396]: Starting albumart workers Oct 25 20:46:54 volumio volumio[19396]: Starting albumart workers Oct 25 20:46:54 volumio volumio[19396]: Starting albumart workers Oct 25 20:46:54 volumio volumio[19396]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:54 volumio volumio[19396]: info: Reloading queue from file Oct 25 20:46:54 volumio volumio[19396]: info: CoreStateMachine::setRepeat false single undefined Oct 25 20:46:54 volumio volumio[19396]: info: CoreStateMachine::pushState Oct 25 20:46:54 volumio volumio[19396]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:54 volumio volumio[19396]: info: CoreStateMachine::setRandom false Oct 25 20:46:54 volumio volumio[19396]: info: CoreStateMachine::pushState Oct 25 20:46:54 volumio volumio[19396]: info: CorePlayQueue::getTrack 0 Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:46:54 volumio volumio[19396]: info: CoreCommandRouter::volumioPushState Oct 25 20:46:54 volumio volumio[19396]: info: Setting Device type: Raspberry PI Oct 25 20:46:54 volumio volumio[19396]: info: Completed loading Core Plugins Oct 25 20:46:54 volumio volumio[19396]: info: Preparing to generate the ALSA configuration file Oct 25 20:46:54 volumio volumio[19396]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 25 20:46:54 volumio volumio[19396]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Oct 25 20:46:54 volumio volumio[19396]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 25 20:46:55 volumio volumio[19396]: info: Asound.conf file unchanged, so no further update is needed Oct 25 20:46:55 volumio volumio-remote-updater[662]: [2024-10-25 20:46:55] [connect] Successful connection Oct 25 20:46:55 volumio volumio[19396]: info: Output device has changed, restarting MPD Oct 25 20:46:55 volumio sudo[19479]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:55 volumio sudo[19479]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:55 volumio volumio[19396]: info: Output device has changed, restarting Shairport Sync Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:55 volumio sudo[19479]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:55 volumio sudo[19481]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:55 volumio sudo[19481]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:55 volumio volumio[19396]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:55 volumio volumio[19396]: info: ___________ START PLUGINS ___________ Oct 25 20:46:55 volumio volumio[19396]: info: ControllerMpd::onStart: Initializing MPD Oct 25 20:46:55 volumio volumio[19396]: info: Creating MPD Configuration file Oct 25 20:46:55 volumio systemd[1]: Stopping Music Player Daemon... Oct 25 20:46:55 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:55 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:55 volumio volumio[19396]: info: [1729914415225] CoreMusicLibrary::Adding element Media Servers Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:55 volumio sudo[19508]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:46:55 volumio sudo[19508]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:55 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:55 volumio sudo[19511]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:46:55 volumio sudo[19511]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:55 volumio sudo[19508]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:55 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 25 20:46:55 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:46:55 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:46:55 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:46:55 volumio volumio[19396]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:55 volumio volumio[19396]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:55 volumio volumio[19396]: info: [1729914415355] CoreMusicLibrary::Adding element Last_100 Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:55 volumio volumio[19396]: info: [1729914415358] CoreMusicLibrary::Adding element Webradio Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:55 volumio volumio[19396]: info: Initializing BBC Radios Oct 25 20:46:55 volumio sudo[19520]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 25 20:46:55 volumio sudo[19520]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:55 volumio sudo[19520]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:46:55 volumio volumio[19396]: info: Creating Spotify config file Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:46:55 volumio volumio[19396]: info: [1729914415437] CoreMusicLibrary::Adding element LastFM Oct 25 20:46:55 volumio volumio[19396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:46:55 volumio volumio[19396]: Cannot find translation for source LastFM Oct 25 20:46:55 volumio volumio[19396]: info: [LastFM] scrobbler initiated! Oct 25 20:46:55 volumio volumio[19396]: info: [LastFM] extended logging: false Oct 25 20:46:55 volumio volumio[19396]: info: [LastFM] try scrobble stream/radio plays: true Oct 25 20:46:55 volumio volumio[19396]: info: [LastFM] Left init routine Oct 25 20:46:55 volumio volumio[19396]: info: [LastFM] Socket already connected: true Oct 25 20:46:55 volumio volumio[19396]: info: Volumio Calling Home Oct 25 20:46:55 volumio volumio[19396]: Unhandled rejection Error: No sockets available, cannot start. Oct 25 20:46:55 volumio volumio[19396]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Oct 25 20:46:55 volumio volumio[19396]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Oct 25 20:46:55 volumio volumio[19396]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Oct 25 20:46:55 volumio volumio[19396]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Oct 25 20:46:55 volumio volumio[19396]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Oct 25 20:46:55 volumio volumio[19396]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Oct 25 20:46:55 volumio volumio[19396]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Oct 25 20:46:55 volumio volumio[19396]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Oct 25 20:46:55 volumio volumio[19396]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Oct 25 20:46:55 volumio volumio[19396]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Oct 25 20:46:55 volumio volumio[19396]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Oct 25 20:46:55 volumio volumio[19396]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Oct 25 20:46:55 volumio volumio[19396]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Oct 25 20:46:55 volumio volumio[19396]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Oct 25 20:46:55 volumio volumio[19396]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Oct 25 20:46:55 volumio volumio[19396]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 25 20:46:55 volumio volumio[19396]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:55 volumio volumio[19396]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Oct 25 20:46:55 volumio volumio[19396]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Oct 25 20:46:55 volumio volumio[19396]: errno: -16, Oct 25 20:46:55 volumio volumio[19396]: code: 'EBUSY', Oct 25 20:46:55 volumio volumio[19396]: syscall: 'getaddrinfo', Oct 25 20:46:55 volumio volumio[19396]: hostname: 'ws.audioscrobbler.com' Oct 25 20:46:55 volumio volumio[19396]: } Oct 25 20:46:55 volumio volumio[19396]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:46:55 volumio sudo[19548]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-25 20:45 Oct 25 20:46:55 volumio sudo[19548]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:56 volumio sudo[19548]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:56 volumio mpd[19526]: Oct 25 20:46 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 25 20:46:56 volumio volumio-remote-updater[662]: [2024-10-25 20:46:56] [info] asio async_read_at_least error: system:104 (Connection reset by peer) Oct 25 20:46:56 volumio volumio-remote-updater[662]: [2024-10-25 20:46:56] [error] handle_read_http_response error: websocketpp.transport:2 (Underlying Transport Error) Oct 25 20:46:56 volumio volumio-remote-updater[662]: [2024-10-25 20:46:56] [info] Error getting remote endpoint: system:107 (Transport endpoint is not connected) Oct 25 20:46:56 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 25 20:46:56 volumio sudo[19481]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:56 volumio systemd[1]: media-WD_BLACK.mount: Succeeded. Oct 25 20:46:56 volumio sudo[19427]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:56 volumio sudo[19511]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:56 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 25 20:46:56 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:56 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:56 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 25 20:46:56 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 107. Oct 25 20:46:56 volumio systemd[1]: Stopped Volumio Backend Module. Oct 25 20:46:56 volumio systemd[1]: Started Volumio Backend Module. Oct 25 20:46:56 volumio systemd[1]: Started dynamicswap service. Oct 25 20:46:56 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:46:56 volumio systemd[1]: Started Music Player Daemon. Oct 25 20:46:57 volumio volumio[19562]: info: ------------------------------------------- Oct 25 20:46:57 volumio volumio[19562]: info: ----- Volumio3 ---- Oct 25 20:46:57 volumio volumio[19562]: info: ------------------------------------------- Oct 25 20:46:57 volumio volumio[19562]: info: ----- System startup ---- Oct 25 20:46:57 volumio volumio[19562]: info: ------------------------------------------- Oct 25 20:46:57 volumio volumio[19562]: info: MYVOLUMIO Environment detected Oct 25 20:46:57 volumio volumio[19562]: info: Plugin folders cleanup Oct 25 20:46:57 volumio volumio[19562]: info: Scanning into folder /volumio/app/plugins/ Oct 25 20:46:57 volumio volumio[19562]: info: Scanning category audio_interface Oct 25 20:46:57 volumio volumio[19562]: info: Scanning category miscellanea Oct 25 20:46:57 volumio volumio[19562]: info: Scanning category music_service Oct 25 20:46:57 volumio volumio[19562]: info: Scanning category plugins.json Oct 25 20:46:57 volumio volumio[19562]: info: Scanning category system_controller Oct 25 20:46:57 volumio volumio[19562]: info: Scanning category user_interface Oct 25 20:46:57 volumio volumio[19562]: info: Scanning into folder /data/plugins/ Oct 25 20:46:57 volumio volumio[19562]: info: Scanning category music_service Oct 25 20:46:57 volumio volumio[19562]: info: Scanning category user_interface Oct 25 20:46:57 volumio volumio[19562]: info: Plugin folders cleanup completed Oct 25 20:46:57 volumio volumio[19562]: info: ------------------------------------------- Oct 25 20:46:57 volumio volumio[19562]: info: ----- Core plugins startup ---- Oct 25 20:46:57 volumio volumio[19562]: info: ------------------------------------------- Oct 25 20:46:57 volumio volumio[19562]: info: Loading plugins from folder /volumio/app/plugins/ Oct 25 20:46:57 volumio volumio[19562]: info: Adding plugin upnp to MyMusic Plugins Oct 25 20:46:57 volumio volumio[19562]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 25 20:46:57 volumio volumio[19562]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 25 20:46:57 volumio volumio[19562]: info: Loading plugins from folder /data/plugins/ Oct 25 20:46:57 volumio volumio[19562]: info: Loading plugin "system"... Oct 25 20:46:57 volumio volumio[19562]: info: Loading plugin "appearance"... Oct 25 20:46:57 volumio wpa_supplicant[954]: wlan0: CTRL-EVENT-SSID-REENABLED id=0 ssid="CenturyLink6201" Oct 25 20:46:57 volumio wpa_supplicant[954]: wlan0: Trying to associate with SSID 'CenturyLink6201' Oct 25 20:46:58 volumio volumio[19562]: info: Loading plugin "network"... Oct 25 20:46:58 volumio volumio[19562]: info: Refreshing Cached IP Addresses Oct 25 20:46:58 volumio sudo[19591]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 25 20:46:58 volumio sudo[19591]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:58 volumio sudo[19591]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:58 volumio volumio[19562]: info: Loading plugin "services"... Oct 25 20:46:58 volumio sudo[19593]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 25 20:46:58 volumio sudo[19593]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:58 volumio volumio[19562]: info: Loading plugin "alsa_controller"... Oct 25 20:46:58 volumio sudo[19593]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:58 volumio sudo[19596]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 25 20:46:58 volumio sudo[19596]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:58 volumio sudo[19596]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:58 volumio kernel: ieee80211 phy0: brcmf_cfg80211_scan: Connecting: status (3) Oct 25 20:46:58 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:46:58 volumio volumio[19562]: info: Loading plugin "wizard"... Oct 25 20:46:58 volumio volumio[19562]: info: Loading plugin "networkfs"... Oct 25 20:46:58 volumio volumio[19562]: info: Starting Udev Watcher for removable devices Oct 25 20:46:58 volumio volumio[19562]: info: Ignoring mount for partition: boot Oct 25 20:46:58 volumio volumio[19562]: info: Ignoring mount for partition: volumio Oct 25 20:46:58 volumio volumio[19562]: info: Ignoring mount for partition: volumio_data Oct 25 20:46:58 volumio volumio[19562]: info: Mounting Device WD_BLACK Oct 25 20:46:58 volumio sudo[19605]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/WD_BLACK -o noatime Oct 25 20:46:58 volumio sudo[19605]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:46:58 volumio sudo[19605]: pam_unix(sudo:session): session closed for user root Oct 25 20:46:58 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:58 volumio volumio[19562]: info: Loading plugin "volumio_command_line_client"... Oct 25 20:46:58 volumio volumio[19562]: info: Loading plugin "upnp"... Oct 25 20:46:58 volumio volumio[19562]: info: [1729914418788] Starting Upmpd Daemon Oct 25 20:46:58 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:58 volumio volumio[19562]: info: Loading plugin "my_music"... Oct 25 20:46:58 volumio volumio[19562]: info: Loading plugin "mpd"... Oct 25 20:46:58 volumio volumio[19562]: info: Loading plugin "upnp_browser"... Oct 25 20:46:59 volumio volumio[19562]: info: Loading plugin "alarm-clock"... Oct 25 20:46:59 volumio volumio[19562]: info: Loading plugin "airplay_emulation"... Oct 25 20:46:59 volumio volumio[19562]: info: Starting Shairport Sync Oct 25 20:46:59 volumio volumio[19562]: info: Loading plugin "last_100"... Oct 25 20:46:59 volumio volumio[19562]: info: Loading plugin "webradio"... Oct 25 20:46:59 volumio volumio[19562]: info: Loading plugin "i2s_dacs"... Oct 25 20:46:59 volumio volumio[19562]: info: Loading plugin "volumiodiscovery"... Oct 25 20:46:59 volumio volumio[19562]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:59 volumio volumio[19562]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:59 volumio node[19562]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:59 volumio volumio[19562]: *** WARNING *** For more information see Oct 25 20:46:59 volumio volumio[19562]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:59 volumio volumio[19562]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:59 volumio volumio[19562]: *** WARNING *** For more information see Oct 25 20:46:59 volumio node[19562]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:59 volumio node[19562]: *** WARNING *** For more information see Oct 25 20:46:59 volumio node[19562]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:46:59 volumio node[19562]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:46:59 volumio node[19562]: *** WARNING *** For more information see Oct 25 20:46:59 volumio volumio[19562]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 25 20:46:59 volumio volumio[19562]: info: Discovery: Started advertising with name: Volumio Oct 25 20:46:59 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:46:59 volumio volumio[19562]: info: Loading plugin "spop"... Oct 25 20:47:00 volumio volumio[19562]: info: Loading plugin "outputs"... Oct 25 20:47:00 volumio volumio[19562]: info: Loading plugin "albumart"... Oct 25 20:47:00 volumio volumio[19562]: info: Plugin example_plugin is not enabled Oct 25 20:47:00 volumio volumio[19562]: info: Loading plugin "inputs"... Oct 25 20:47:00 volumio volumio[19562]: info: Loading plugin "updater_comm"... Oct 25 20:47:00 volumio volumio[19562]: info: Plugin mpdemulation is not enabled Oct 25 20:47:00 volumio volumio[19562]: info: Loading plugin "rest_api"... Oct 25 20:47:00 volumio volumio[19562]: info: Loading plugin "websocket"... Oct 25 20:47:00 volumio volumio[19562]: info: Starting Socket.io Server version 2.3.0 Oct 25 20:47:00 volumio volumio[19562]: info: Loading plugin "lastfm"... Oct 25 20:47:00 volumio volumio[19562]: Forking 3 albumart workers Oct 25 20:47:00 volumio volumio[19562]: info: Loading i18n strings for locale en Oct 25 20:47:00 volumio volumio[19562]: Updating browse sources language Oct 25 20:47:00 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:47:00 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:47:00 volumio volumio[19562]: info: CoreCommandRouter::initPlayerControls Oct 25 20:47:00 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:00 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:00 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:00 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:00 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:00 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:00 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:00 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:00 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:47:00 volumio volumio[19562]: Express server listening on port 3000 Oct 25 20:47:00 volumio volumio[19562]: [Metrics] WebUI: 3s 639.46ms Oct 25 20:47:00 volumio volumio[19562]: info: CoreStateMachine::resetVolumioState Oct 25 20:47:00 volumio volumio[19562]: info: CoreStateMachine::getcurrentVolume Oct 25 20:47:00 volumio volumio[19562]: info: CoreCommandRouter::volumioRetrievevolume Oct 25 20:47:00 volumio volumio[19562]: info: CoreStateMachine::pushState Oct 25 20:47:00 volumio volumio[19562]: info: CorePlayQueue::getTrack 0 Oct 25 20:47:00 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:47:00 volumio volumio[19562]: info: CoreCommandRouter::volumioPushState Oct 25 20:47:00 volumio volumio[19562]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Oct 25 20:47:00 volumio volumio[19562]: wlan0 Interface doesn't support scanning : Resource temporarily unavailable Oct 25 20:47:00 volumio volumio[19562]: info: Cannot use regular scanning, forcing with ap-force Oct 25 20:47:00 volumio volumio[19562]: Starting albumart workers Oct 25 20:47:00 volumio volumio[19562]: Starting albumart workers Oct 25 20:47:00 volumio sudo[19643]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Oct 25 20:47:00 volumio sudo[19643]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:47:00 volumio sudo[19643]: pam_unix(sudo:session): session closed for user root Oct 25 20:47:00 volumio volumio[19562]: command failed: Resource temporarily unavailable (-11) Oct 25 20:47:00 volumio volumio[19562]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Oct 25 20:47:00 volumio volumio[19562]: command failed: Resource temporarily unavailable (-11) Oct 25 20:47:00 volumio kernel: ieee80211 phy0: brcmf_cfg80211_scan: Connecting: status (3) Oct 25 20:47:00 volumio volumio[19562]: Starting albumart workers Oct 25 20:47:00 volumio volumio[19562]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 1 Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:47:01 volumio volumio[19562]: info: Reloading queue from file Oct 25 20:47:01 volumio volumio[19562]: info: CoreStateMachine::setRepeat false single undefined Oct 25 20:47:01 volumio volumio[19562]: info: CoreStateMachine::pushState Oct 25 20:47:01 volumio volumio[19562]: info: CorePlayQueue::getTrack 0 Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::volumioPushState Oct 25 20:47:01 volumio volumio[19562]: info: CoreStateMachine::setRandom false Oct 25 20:47:01 volumio volumio[19562]: info: CoreStateMachine::pushState Oct 25 20:47:01 volumio volumio[19562]: info: CorePlayQueue::getTrack 0 Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::volumioPushState Oct 25 20:47:01 volumio volumio[19562]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 25 20:47:01 volumio volumio[19562]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Oct 25 20:47:01 volumio volumio[19562]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 25 20:47:01 volumio volumio[19562]: info: Setting Device type: Raspberry PI Oct 25 20:47:01 volumio volumio[19562]: info: Completed loading Core Plugins Oct 25 20:47:01 volumio volumio[19562]: info: Preparing to generate the ALSA configuration file Oct 25 20:47:01 volumio dhcpcd[966]: wlan0: carrier acquired Oct 25 20:47:01 volumio dhcpcd[966]: wlan0: connected to Access Point `CenturyLink6201' Oct 25 20:47:01 volumio wpa_supplicant[954]: wlan0: Associated with 02:6a:e3:86:fe:a7 Oct 25 20:47:01 volumio wpa_supplicant[954]: wlan0: CTRL-EVENT-CONNECTED - Connection to 02:6a:e3:86:fe:a7 completed [id=0 id_str=] Oct 25 20:47:01 volumio wpa_supplicant[954]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0 Oct 25 20:47:01 volumio wpa_supplicant[954]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=US Oct 25 20:47:01 volumio dhcpcd[966]: DUID 00:01:00:01:2d:69:1d:e6:dc:a6:32:a6:cd:36 Oct 25 20:47:01 volumio dhcpcd[966]: wlan0: IAID 32:a6:cd:36 Oct 25 20:47:01 volumio dhcpcd[966]: wlan0: adding address fe80::3b72:ad2e:3b1:ed9d Oct 25 20:47:01 volumio dhcpcd[966]: ipv6_addaddr1: Permission denied Oct 25 20:47:01 volumio dhcpcd[966]: wlan0: carrier lost Oct 25 20:47:01 volumio dhcpcd[966]: wlan0: carrier acquired Oct 25 20:47:01 volumio volumio[19562]: info: Asound.conf file unchanged, so no further update is needed Oct 25 20:47:01 volumio dhcpcd[966]: wlan0: IAID 32:a6:cd:36 Oct 25 20:47:01 volumio volumio[19562]: info: Output device has changed, restarting MPD Oct 25 20:47:01 volumio volumio[19562]: info: Output device has changed, restarting Shairport Sync Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:47:01 volumio sudo[19686]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:47:01 volumio sudo[19686]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:47:01 volumio sudo[19686]: pam_unix(sudo:session): session closed for user root Oct 25 20:47:01 volumio sudo[19688]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:47:01 volumio sudo[19688]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:47:01 volumio volumio[19562]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:47:01 volumio systemd[1]: Stopping Music Player Daemon... Oct 25 20:47:01 volumio volumio[19562]: info: ___________ START PLUGINS ___________ Oct 25 20:47:01 volumio volumio[19562]: info: ControllerMpd::onStart: Initializing MPD Oct 25 20:47:01 volumio volumio[19562]: info: Creating MPD Configuration file Oct 25 20:47:01 volumio sudo[19695]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:47:01 volumio sudo[19695]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:47:01 volumio volumio[19562]: info: [1729914421428] CoreMusicLibrary::Adding element Media Servers Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:47:01 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:47:01 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:47:01 volumio sudo[19695]: pam_unix(sudo:session): session closed for user root Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:47:01 volumio sudo[19698]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:47:01 volumio sudo[19698]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:47:01 volumio volumio[19562]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:47:01 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:47:01 volumio dhcpcd[966]: wlan0: rebinding lease of 192.168.0.32 Oct 25 20:47:01 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 25 20:47:01 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:47:01 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:47:01 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:47:01 volumio volumio[19562]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:47:01 volumio volumio[19562]: info: [1729914421520] CoreMusicLibrary::Adding element Last_100 Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:47:01 volumio volumio[19562]: info: [1729914421523] CoreMusicLibrary::Adding element Webradio Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:47:01 volumio volumio[19562]: info: Initializing BBC Radios Oct 25 20:47:01 volumio sudo[19707]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 25 20:47:01 volumio sudo[19707]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:47:01 volumio sudo[19707]: pam_unix(sudo:session): session closed for user root Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:47:01 volumio volumio[19562]: info: Creating Spotify config file Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:47:01 volumio volumio[19562]: info: [1729914421602] CoreMusicLibrary::Adding element LastFM Oct 25 20:47:01 volumio volumio[19562]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:47:01 volumio volumio[19562]: Cannot find translation for source LastFM Oct 25 20:47:01 volumio volumio[19562]: info: [LastFM] scrobbler initiated! Oct 25 20:47:01 volumio volumio[19562]: info: [LastFM] extended logging: false Oct 25 20:47:01 volumio volumio[19562]: info: [LastFM] try scrobble stream/radio plays: true Oct 25 20:47:01 volumio volumio[19562]: info: [LastFM] Left init routine Oct 25 20:47:01 volumio volumio[19562]: info: [LastFM] Socket already connected: true Oct 25 20:47:01 volumio volumio[19562]: info: Volumio Calling Home Oct 25 20:47:01 volumio volumio[19562]: Unhandled rejection Error: No sockets available, cannot start. Oct 25 20:47:01 volumio volumio[19562]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Oct 25 20:47:01 volumio volumio[19562]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Oct 25 20:47:01 volumio volumio[19562]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Oct 25 20:47:01 volumio volumio[19562]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Oct 25 20:47:01 volumio volumio[19562]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Oct 25 20:47:01 volumio volumio[19562]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Oct 25 20:47:01 volumio volumio[19562]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Oct 25 20:47:01 volumio volumio[19562]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Oct 25 20:47:01 volumio volumio[19562]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Oct 25 20:47:01 volumio volumio[19562]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Oct 25 20:47:01 volumio volumio[19562]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Oct 25 20:47:01 volumio volumio[19562]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Oct 25 20:47:01 volumio volumio[19562]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Oct 25 20:47:01 volumio volumio[19562]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Oct 25 20:47:01 volumio volumio[19562]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Oct 25 20:47:01 volumio volumio[19562]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 25 20:47:01 volumio volumio[19562]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:47:01 volumio volumio[19562]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Oct 25 20:47:01 volumio volumio[19562]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Oct 25 20:47:01 volumio volumio[19562]: errno: -16, Oct 25 20:47:01 volumio volumio[19562]: code: 'EBUSY', Oct 25 20:47:01 volumio volumio[19562]: syscall: 'getaddrinfo', Oct 25 20:47:01 volumio volumio[19562]: hostname: 'ws.audioscrobbler.com' Oct 25 20:47:01 volumio volumio[19562]: } Oct 25 20:47:01 volumio volumio[19562]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:47:01 volumio dhcpcd[966]: wlan0: soliciting an IPv6 router Oct 25 20:47:02 volumio sudo[19732]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-25 20:46 Oct 25 20:47:02 volumio sudo[19732]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:47:02 volumio sudo[19732]: pam_unix(sudo:session): session closed for user root Oct 25 20:47:02 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Oct 25 20:47:02 volumio sudo[19698]: pam_unix(sudo:session): session closed for user root Oct 25 20:47:02 volumio sudo[19688]: pam_unix(sudo:session): session closed for user root Oct 25 20:47:02 volumio systemd[1]: media-WD_BLACK.mount: Succeeded. Oct 25 20:47:02 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Oct 25 20:47:02 volumio mpd[19719]: Oct 25 20:47 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 25 20:47:02 volumio systemd[1]: Started dynamicswap service. Oct 25 20:47:02 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Oct 25 20:47:02 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 108. Oct 25 20:47:02 volumio systemd[1]: dynamicswap.service: Succeeded. Oct 25 20:47:02 volumio systemd[1]: Stopped Volumio Backend Module. Oct 25 20:47:02 volumio systemd[1]: Started Volumio Backend Module. Oct 25 20:47:02 volumio systemd[1]: Started Music Player Daemon. Oct 25 20:47:02 volumio dhcpcd[966]: wlan0: probing address 192.168.0.32/24 Oct 25 20:47:03 volumio volumio[19745]: info: ------------------------------------------- Oct 25 20:47:03 volumio volumio[19745]: info: ----- Volumio3 ---- Oct 25 20:47:03 volumio volumio[19745]: info: ------------------------------------------- Oct 25 20:47:03 volumio volumio[19745]: info: ----- System startup ---- Oct 25 20:47:03 volumio volumio[19745]: info: ------------------------------------------- Oct 25 20:47:03 volumio volumio-remote-updater[662]: [2024-10-25 20:47:03] [connect] Successful connection Oct 25 20:47:03 volumio volumio[19745]: info: MYVOLUMIO Environment detected Oct 25 20:47:03 volumio volumio[19745]: info: Plugin folders cleanup Oct 25 20:47:03 volumio volumio[19745]: info: Scanning into folder /volumio/app/plugins/ Oct 25 20:47:03 volumio volumio[19745]: info: Scanning category audio_interface Oct 25 20:47:03 volumio volumio[19745]: info: Scanning category miscellanea Oct 25 20:47:03 volumio volumio[19745]: info: Scanning category music_service Oct 25 20:47:03 volumio volumio[19745]: info: Scanning category plugins.json Oct 25 20:47:03 volumio volumio[19745]: info: Scanning category system_controller Oct 25 20:47:03 volumio volumio[19745]: info: Scanning category user_interface Oct 25 20:47:03 volumio volumio[19745]: info: Scanning into folder /data/plugins/ Oct 25 20:47:03 volumio volumio[19745]: info: Scanning category music_service Oct 25 20:47:03 volumio volumio[19745]: info: Scanning category user_interface Oct 25 20:47:03 volumio volumio[19745]: info: Plugin folders cleanup completed Oct 25 20:47:03 volumio volumio[19745]: info: ------------------------------------------- Oct 25 20:47:03 volumio volumio[19745]: info: ----- Core plugins startup ---- Oct 25 20:47:03 volumio volumio[19745]: info: ------------------------------------------- Oct 25 20:47:03 volumio volumio[19745]: info: Loading plugins from folder /volumio/app/plugins/ Oct 25 20:47:03 volumio volumio[19745]: info: Adding plugin upnp to MyMusic Plugins Oct 25 20:47:03 volumio volumio[19745]: info: Adding plugin airplay_emulation to MyMusic Plugins Oct 25 20:47:03 volumio volumio[19745]: info: Adding plugin upnp_browser to MyMusic Plugins Oct 25 20:47:03 volumio volumio[19745]: info: Loading plugins from folder /data/plugins/ Oct 25 20:47:03 volumio volumio[19745]: info: Loading plugin "system"... Oct 25 20:47:03 volumio volumio[19745]: info: Loading plugin "appearance"... Oct 25 20:47:04 volumio volumio[19745]: info: Loading plugin "network"... Oct 25 20:47:04 volumio volumio[19745]: info: Refreshing Cached IP Addresses Oct 25 20:47:04 volumio sudo[19768]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 25 20:47:04 volumio sudo[19768]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:47:04 volumio sudo[19768]: pam_unix(sudo:session): session closed for user root Oct 25 20:47:04 volumio sudo[19770]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 25 20:47:04 volumio volumio[19745]: info: Loading plugin "services"... Oct 25 20:47:04 volumio sudo[19770]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:47:04 volumio volumio[19745]: info: Loading plugin "alsa_controller"... Oct 25 20:47:04 volumio sudo[19770]: pam_unix(sudo:session): session closed for user root Oct 25 20:47:04 volumio sudo[19773]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Oct 25 20:47:04 volumio sudo[19773]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:47:04 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:47:04 volumio volumio[19745]: info: Loading plugin "wizard"... Oct 25 20:47:04 volumio volumio[19745]: info: Loading plugin "networkfs"... Oct 25 20:47:04 volumio volumio[19745]: info: Starting Udev Watcher for removable devices Oct 25 20:47:04 volumio volumio[19745]: info: Ignoring mount for partition: boot Oct 25 20:47:04 volumio volumio[19745]: info: Ignoring mount for partition: volumio Oct 25 20:47:04 volumio volumio[19745]: info: Ignoring mount for partition: volumio_data Oct 25 20:47:04 volumio volumio[19745]: info: Mounting Device WD_BLACK Oct 25 20:47:04 volumio sudo[19782]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/WD_BLACK -o noatime Oct 25 20:47:04 volumio sudo[19782]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:47:04 volumio sudo[19782]: pam_unix(sudo:session): session closed for user root Oct 25 20:47:04 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:47:04 volumio volumio[19745]: info: Loading plugin "volumio_command_line_client"... Oct 25 20:47:04 volumio volumio[19745]: info: Loading plugin "upnp"... Oct 25 20:47:04 volumio volumio[19745]: info: [1729914424868] Starting Upmpd Daemon Oct 25 20:47:04 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:47:04 volumio volumio[19745]: info: Loading plugin "my_music"... Oct 25 20:47:04 volumio volumio[19745]: info: Loading plugin "mpd"... Oct 25 20:47:05 volumio volumio[19745]: info: Loading plugin "upnp_browser"... Oct 25 20:47:05 volumio volumio[19745]: info: Loading plugin "alarm-clock"... Oct 25 20:47:05 volumio volumio[19745]: info: Loading plugin "airplay_emulation"... Oct 25 20:47:05 volumio volumio[19745]: info: Starting Shairport Sync Oct 25 20:47:05 volumio volumio[19745]: info: Loading plugin "last_100"... Oct 25 20:47:05 volumio volumio[19745]: info: Loading plugin "webradio"... Oct 25 20:47:05 volumio volumio[19745]: info: Loading plugin "i2s_dacs"... Oct 25 20:47:05 volumio volumio[19745]: info: Loading plugin "volumiodiscovery"... Oct 25 20:47:05 volumio volumio[19745]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:47:05 volumio node[19745]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Oct 25 20:47:05 volumio node[19745]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:47:05 volumio volumio[19745]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:47:05 volumio volumio[19745]: *** WARNING *** For more information see Oct 25 20:47:05 volumio volumio[19745]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:47:05 volumio volumio[19745]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:47:05 volumio volumio[19745]: *** WARNING *** For more information see Oct 25 20:47:05 volumio node[19745]: *** WARNING *** For more information see Oct 25 20:47:05 volumio node[19745]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Oct 25 20:47:05 volumio node[19745]: *** WARNING *** Please fix your application to use the native API of Avahi! Oct 25 20:47:05 volumio node[19745]: *** WARNING *** For more information see Oct 25 20:47:05 volumio volumio[19745]: info: Applying required configuration parameters for plugin volumiodiscovery Oct 25 20:47:05 volumio volumio[19745]: info: Discovery: Started advertising with name: Volumio Oct 25 20:47:05 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Oct 25 20:47:05 volumio volumio[19745]: info: Loading plugin "spop"... Oct 25 20:47:06 volumio volumio[19745]: info: Loading plugin "outputs"... Oct 25 20:47:06 volumio volumio[19745]: info: Loading plugin "albumart"... Oct 25 20:47:06 volumio volumio[19745]: info: Plugin example_plugin is not enabled Oct 25 20:47:06 volumio volumio[19745]: info: Loading plugin "inputs"... Oct 25 20:47:06 volumio volumio[19745]: info: Loading plugin "updater_comm"... Oct 25 20:47:06 volumio volumio[19745]: info: Plugin mpdemulation is not enabled Oct 25 20:47:06 volumio volumio[19745]: info: Loading plugin "rest_api"... Oct 25 20:47:06 volumio volumio[19745]: info: Loading plugin "websocket"... Oct 25 20:47:06 volumio volumio[19745]: info: Starting Socket.io Server version 2.3.0 Oct 25 20:47:06 volumio volumio[19745]: info: Loading plugin "lastfm"... Oct 25 20:47:06 volumio volumio[19745]: Forking 3 albumart workers Oct 25 20:47:06 volumio volumio[19745]: info: Loading i18n strings for locale en Oct 25 20:47:06 volumio volumio[19745]: Updating browse sources language Oct 25 20:47:06 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:47:06 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:47:06 volumio volumio[19745]: info: CoreCommandRouter::initPlayerControls Oct 25 20:47:06 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:06 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:06 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:06 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:06 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:06 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:06 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:06 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:06 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:47:06 volumio volumio[19745]: Express server listening on port 3000 Oct 25 20:47:06 volumio volumio[19745]: [Metrics] WebUI: 3s 585.70ms Oct 25 20:47:06 volumio volumio[19745]: info: CoreStateMachine::resetVolumioState Oct 25 20:47:06 volumio volumio[19745]: info: CoreStateMachine::getcurrentVolume Oct 25 20:47:06 volumio volumio[19745]: info: CoreCommandRouter::volumioRetrievevolume Oct 25 20:47:06 volumio volumio[19745]: info: CoreStateMachine::pushState Oct 25 20:47:06 volumio volumio[19745]: info: CorePlayQueue::getTrack 0 Oct 25 20:47:06 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:47:06 volumio volumio[19745]: info: CoreCommandRouter::volumioPushState Oct 25 20:47:06 volumio volumio-remote-updater[662]: [2024-10-25 20:47:06] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1729914423 101 Oct 25 20:47:06 volumio volumio[19745]: 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: 1 Oct 25 20:47:06 volumio volumio[19745]: Starting albumart workers Oct 25 20:47:06 volumio volumio[19745]: Starting albumart workers Oct 25 20:47:06 volumio volumio[19745]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Oct 25 20:47:06 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:47:06 volumio volumio[19745]: info: Reloading queue from file Oct 25 20:47:07 volumio volumio[19745]: Starting albumart workers Oct 25 20:47:07 volumio volumio[19745]: info: CoreStateMachine::setRepeat false single undefined Oct 25 20:47:07 volumio volumio[19745]: info: CoreStateMachine::pushState Oct 25 20:47:07 volumio volumio[19745]: info: CorePlayQueue::getTrack 0 Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::volumioPushState Oct 25 20:47:07 volumio volumio[19745]: info: CoreStateMachine::setRandom false Oct 25 20:47:07 volumio volumio[19745]: info: CoreStateMachine::pushState Oct 25 20:47:07 volumio volumio[19745]: info: CorePlayQueue::getTrack 0 Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::volumioPushState Oct 25 20:47:07 volumio volumio[19745]: info: USB Boot Capable - Checking Install to Disk functions for: bootusb Oct 25 20:47:07 volumio volumio[19745]: info: USB Boot Capable - System SBC Revision found in cpuinfo: c03112 Oct 25 20:47:07 volumio volumio[19745]: info: USB Boot Capable - Found matching device in SBC capable list: Raspberry PI Oct 25 20:47:07 volumio volumio[19745]: info: Setting Device type: Raspberry PI Oct 25 20:47:07 volumio volumio[19745]: info: Completed loading Core Plugins Oct 25 20:47:07 volumio volumio[19745]: info: Preparing to generate the ALSA configuration file Oct 25 20:47:07 volumio volumio[19745]: info: Asound.conf file unchanged, so no further update is needed Oct 25 20:47:07 volumio volumio[19745]: info: Output device has changed, restarting MPD Oct 25 20:47:07 volumio volumio[19745]: info: Output device has changed, restarting Shairport Sync Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:47:07 volumio sudo[19825]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:47:07 volumio sudo[19825]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:47:07 volumio sudo[19826]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:47:07 volumio sudo[19826]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:47:07 volumio sudo[19825]: pam_unix(sudo:session): session closed for user root Oct 25 20:47:07 volumio systemd[1]: Stopping Music Player Daemon... Oct 25 20:47:07 volumio volumio[19745]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:47:07 volumio volumio[19745]: info: ___________ START PLUGINS ___________ Oct 25 20:47:07 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:47:07 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:47:07 volumio volumio[19745]: info: ControllerMpd::onStart: Initializing MPD Oct 25 20:47:07 volumio volumio[19745]: info: Creating MPD Configuration file Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:47:07 volumio volumio[19745]: info: [1729914427405] CoreMusicLibrary::Adding element Media Servers Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:47:07 volumio sudo[19851]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 25 20:47:07 volumio sudo[19851]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:47:07 volumio sudo[19852]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 25 20:47:07 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:47:07 volumio sudo[19852]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:47:07 volumio sudo[19851]: pam_unix(sudo:session): session closed for user root Oct 25 20:47:07 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Oct 25 20:47:07 volumio systemd[1]: mpd.service: Succeeded. Oct 25 20:47:07 volumio systemd[1]: Stopped Music Player Daemon. Oct 25 20:47:07 volumio systemd[1]: Starting Music Player Daemon... Oct 25 20:47:07 volumio volumio[19745]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:47:07 volumio volumio[19745]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:47:07 volumio volumio[19745]: info: [1729914427518] CoreMusicLibrary::Adding element Last_100 Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:47:07 volumio volumio[19745]: info: [1729914427521] CoreMusicLibrary::Adding element Webradio Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:47:07 volumio volumio[19745]: info: Initializing BBC Radios Oct 25 20:47:07 volumio sudo[19858]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Oct 25 20:47:07 volumio sudo[19858]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 25 20:47:07 volumio sudo[19858]: pam_unix(sudo:session): session closed for user root Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 25 20:47:07 volumio volumio[19745]: info: Creating Spotify config file Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Oct 25 20:47:07 volumio volumio[19745]: info: [1729914427604] CoreMusicLibrary::Adding element LastFM Oct 25 20:47:07 volumio volumio[19745]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 25 20:47:07 volumio volumio[19745]: Cannot find translation for source LastFM Oct 25 20:47:07 volumio volumio[19745]: info: [LastFM] scrobbler initiated! Oct 25 20:47:07 volumio volumio[19745]: info: [LastFM] extended logging: false Oct 25 20:47:07 volumio volumio[19745]: info: [LastFM] try scrobble stream/radio plays: true Oct 25 20:47:07 volumio volumio[19745]: info: [LastFM] Left init routine Oct 25 20:47:07 volumio volumio[19745]: info: [LastFM] Socket already connected: true Oct 25 20:47:07 volumio volumio[19745]: info: Volumio Calling Home Oct 25 20:47:07 volumio volumio[19745]: Unhandled rejection Error: No sockets available, cannot start. Oct 25 20:47:07 volumio volumio[19745]: at SsdpClient.SSDP._createSockets (/volumio/node_modules/node-ssdp/lib/index.js:186:11) Oct 25 20:47:07 volumio volumio[19745]: at SsdpClient.SSDP._start (/volumio/node_modules/node-ssdp/lib/index.js:229:10) Oct 25 20:47:07 volumio volumio[19745]: at /volumio/node_modules/node-ssdp/lib/client.js:60:10 Oct 25 20:47:07 volumio volumio[19745]: at Promise._execute (/volumio/node_modules/bluebird/js/release/debuggability.js:384:9) Oct 25 20:47:07 volumio volumio[19745]: at Promise._resolveFromExecutor (/volumio/node_modules/bluebird/js/release/promise.js:518:18) Oct 25 20:47:07 volumio volumio[19745]: at new Promise (/volumio/node_modules/bluebird/js/release/promise.js:103:10) Oct 25 20:47:07 volumio volumio[19745]: at SsdpClient.start (/volumio/node_modules/node-ssdp/lib/client.js:54:10) Oct 25 20:47:07 volumio volumio[19745]: at SsdpClient.search (/volumio/node_modules/node-ssdp/lib/client.js:82:17) Oct 25 20:47:07 volumio volumio[19745]: at ControllerUPNPBrowser.onStart (/volumio/app/plugins/music_service/upnp_browser/index.js:126:12) Oct 25 20:47:07 volumio volumio[19745]: at PluginManager.startCorePlugin (/volumio/app/pluginmanager.js:398:24) Oct 25 20:47:07 volumio volumio[19745]: at HashMap. (/volumio/app/pluginmanager.js:496:31) Oct 25 20:47:07 volumio volumio[19745]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Oct 25 20:47:07 volumio volumio[19745]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Oct 25 20:47:07 volumio volumio[19745]: at PluginManager.startCorePlugins (/volumio/app/pluginmanager.js:495:20) Oct 25 20:47:07 volumio volumio[19745]: at Promise._successFn (/volumio/app/pluginmanager.js:142:29) Oct 25 20:47:07 volumio volumio[19745]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) Oct 25 20:47:07 volumio volumio[19745]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:47:07 volumio volumio[19745]: Error: getaddrinfo EBUSY ws.audioscrobbler.com Oct 25 20:47:07 volumio volumio[19745]: at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:67:26) { Oct 25 20:47:07 volumio volumio[19745]: errno: -16, Oct 25 20:47:07 volumio volumio[19745]: code: 'EBUSY', Oct 25 20:47:07 volumio volumio[19745]: syscall: 'getaddrinfo', Oct 25 20:47:07 volumio volumio[19745]: hostname: 'ws.audioscrobbler.com' Oct 25 20:47:07 volumio volumio[19745]: } Oct 25 20:47:07 volumio volumio[19745]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 25 20:47:08 volumio sudo[19894]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-25 20:46 Oct 25 20:47:08 volumio sudo[19894]: 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"