-- Logs begin at Thu 2019-02-14 04:12:00 CST, end at Wed 2024-04-03 09:23:41 CDT. -- Apr 03 09:22:00 music-server volumio[594]: info: Plugin folders cleanup Apr 03 09:22:00 music-server volumio[594]: info: Scanning into folder /volumio/app/plugins/ Apr 03 09:22:00 music-server volumio[594]: info: Scanning category audio_interface Apr 03 09:22:00 music-server volumio[594]: info: Scanning category miscellanea Apr 03 09:22:00 music-server volumio[594]: info: Scanning category music_service Apr 03 09:22:00 music-server volumio[594]: info: Scanning category plugins.json Apr 03 09:22:00 music-server volumio[594]: info: Scanning category system_controller Apr 03 09:22:00 music-server volumio[594]: info: Scanning category user_interface Apr 03 09:22:00 music-server volumio[594]: info: Scanning into folder /data/plugins/ Apr 03 09:22:00 music-server volumio[594]: info: Scanning category audio_interface Apr 03 09:22:00 music-server volumio[594]: info: Scanning category music_service Apr 03 09:22:00 music-server volumio[594]: info: Scanning category user_interface Apr 03 09:22:00 music-server volumio[594]: info: Plugin folders cleanup completed Apr 03 09:22:00 music-server volumio[594]: info: ------------------------------------------- Apr 03 09:22:00 music-server volumio[594]: info: ----- Core plugins startup ---- Apr 03 09:22:00 music-server volumio[594]: info: ------------------------------------------- Apr 03 09:22:00 music-server volumio[594]: info: Loading plugins from folder /volumio/app/plugins/ Apr 03 09:22:00 music-server volumio[594]: info: Adding plugin upnp to MyMusic Plugins Apr 03 09:22:00 music-server volumio[594]: info: Adding plugin airplay_emulation to MyMusic Plugins Apr 03 09:22:00 music-server volumio[594]: info: Adding plugin upnp_browser to MyMusic Plugins Apr 03 09:22:00 music-server volumio[594]: info: Loading plugins from folder /data/plugins/ Apr 03 09:22:00 music-server volumio[594]: info: Loading plugin "system"... Apr 03 09:22:00 music-server volumio[594]: info: Loading plugin "appearance"... Apr 03 09:22:01 music-server volumio-remote-updater[396]: [2024-04-03 09:22:01] [connect] Successful connection Apr 03 09:22:03 music-server volumio[594]: info: Loading plugin "network"... Apr 03 09:22:03 music-server volumio[594]: info: Refreshing Cached IP Addresses Apr 03 09:22:03 music-server volumio[594]: info: Loading plugin "services"... Apr 03 09:22:03 music-server volumio[594]: info: Loading plugin "alsa_controller"... Apr 03 09:22:03 music-server sudo[686]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 03 09:22:03 music-server sudo[688]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 03 09:22:03 music-server sudo[690]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Apr 03 09:22:03 music-server sudo[688]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:22:03 music-server sudo[686]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:22:03 music-server sudo[690]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:22:03 music-server sudo[686]: pam_unix(sudo:session): session closed for user root Apr 03 09:22:03 music-server sudo[688]: pam_unix(sudo:session): session closed for user root Apr 03 09:22:03 music-server sudo[690]: pam_unix(sudo:session): session closed for user root Apr 03 09:22:03 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 03 09:22:03 music-server volumio[594]: info: Loading plugin "wizard"... Apr 03 09:22:03 music-server volumio[594]: info: Loading plugin "networkfs"... Apr 03 09:22:03 music-server volumio[594]: info: Starting Udev Watcher for removable devices Apr 03 09:22:03 music-server volumio[594]: info: Ignoring mount for partition: boot Apr 03 09:22:03 music-server volumio[594]: info: Ignoring mount for partition: volumio Apr 03 09:22:03 music-server volumio[594]: info: Ignoring mount for partition: volumio_data Apr 03 09:22:03 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 03 09:22:03 music-server volumio[594]: info: Loading plugin "volumio_command_line_client"... Apr 03 09:22:03 music-server volumio[594]: info: Loading plugin "upnp"... Apr 03 09:22:03 music-server volumio[594]: info: [1712154123856] Starting Upmpd Daemon Apr 03 09:22:03 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 03 09:22:03 music-server volumio[594]: info: Loading plugin "my_music"... Apr 03 09:22:03 music-server volumio[594]: info: Loading plugin "mpd"... Apr 03 09:22:04 music-server volumio[594]: info: Loading plugin "upnp_browser"... Apr 03 09:22:05 music-server volumio[594]: info: Loading plugin "alarm-clock"... Apr 03 09:22:06 music-server volumio[594]: info: Loading plugin "airplay_emulation"... Apr 03 09:22:06 music-server volumio[594]: info: Starting Shairport Sync Apr 03 09:22:06 music-server volumio[594]: info: Loading plugin "last_100"... Apr 03 09:22:06 music-server volumio[594]: info: Loading plugin "webradio"... Apr 03 09:22:06 music-server volumio[594]: info: Loading plugin "i2s_dacs"... Apr 03 09:22:06 music-server volumio[594]: info: Loading plugin "volumiodiscovery"... Apr 03 09:22:06 music-server volumio[594]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 03 09:22:06 music-server volumio[594]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 03 09:22:06 music-server volumio[594]: *** WARNING *** For more information see Apr 03 09:22:06 music-server node[594]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Apr 03 09:22:06 music-server volumio[594]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 03 09:22:06 music-server volumio[594]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 03 09:22:06 music-server volumio[594]: *** WARNING *** For more information see Apr 03 09:22:06 music-server node[594]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 03 09:22:06 music-server node[594]: *** WARNING *** For more information see Apr 03 09:22:06 music-server node[594]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Apr 03 09:22:06 music-server node[594]: *** WARNING *** Please fix your application to use the native API of Avahi! Apr 03 09:22:06 music-server node[594]: *** WARNING *** For more information see Apr 03 09:22:06 music-server volumio[594]: info: Applying required configuration parameters for plugin volumiodiscovery Apr 03 09:22:06 music-server volumio[594]: info: Discovery: Started advertising with name: Music server Apr 03 09:22:06 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 03 09:22:06 music-server volumio[594]: info: Loading plugin "bandcamp"... Apr 03 09:22:09 music-server volumio[594]: info: Loading plugin "calmradio"... Apr 03 09:22:11 music-server volumio[594]: info: Loading plugin "mixcloud"... Apr 03 09:22:13 music-server volumio[594]: info: Loading plugin "soundcloud"... Apr 03 09:22:14 music-server volumio[594]: info: Loading plugin "spop"... Apr 03 09:22:15 music-server systemd[1]: systemd-fsckd.service: Succeeded. Apr 03 09:22:16 music-server volumio-remote-updater[396]: [2024-04-03 09:22:16] [connect] Successful connection Apr 03 09:22:17 music-server volumio[594]: info: Loading plugin "youtube2"... Apr 03 09:22:20 music-server volumio[594]: info: Loading plugin "ytmusic"... Apr 03 09:22:23 music-server volumio[594]: info: Loading plugin "now_playing"... Apr 03 09:22:26 music-server volumio[594]: info: Loading plugin "outputs"... Apr 03 09:22:26 music-server volumio[594]: info: Loading plugin "albumart"... Apr 03 09:22:26 music-server volumio[594]: info: Plugin example_plugin is not enabled Apr 03 09:22:26 music-server volumio[594]: info: Loading plugin "inputs"... Apr 03 09:22:26 music-server volumio[594]: info: Loading plugin "updater_comm"... Apr 03 09:22:27 music-server volumio[594]: info: Plugin mpdemulation is not enabled Apr 03 09:22:27 music-server volumio[594]: info: Loading plugin "rest_api"... Apr 03 09:22:27 music-server volumio[594]: info: Loading plugin "websocket"... Apr 03 09:22:27 music-server volumio[594]: info: Loading plugin "fusiondsp"... Apr 03 09:22:27 music-server volumio[594]: Forking 3 albumart workers Apr 03 09:22:28 music-server volumio[594]: info: Applying required configuration parameters for plugin fusiondsp Apr 03 09:22:28 music-server volumio[594]: info: Loading plugin "80s80s"... Apr 03 09:22:29 music-server volumio[594]: Starting albumart workers Apr 03 09:22:29 music-server volumio[594]: Starting albumart workers Apr 03 09:22:29 music-server volumio[594]: info: Applying required configuration parameters for plugin 80s80s Apr 03 09:22:29 music-server volumio[594]: Starting albumart workers Apr 03 09:22:29 music-server volumio[594]: info: [1712154149520] [80s80s] API delay: 30 Apr 03 09:22:29 music-server volumio[594]: info: Loading plugin "RoonBridge"... Apr 03 09:22:30 music-server volumio[594]: info: Applying required configuration parameters for plugin RoonBridge Apr 03 09:22:30 music-server volumio[594]: info: Loading plugin "motherearthradio"... Apr 03 09:22:31 music-server volumio-remote-updater[396]: [2024-04-03 09:22:31] [connect] Successful connection Apr 03 09:22:31 music-server volumio[594]: info: Applying required configuration parameters for plugin motherearthradio Apr 03 09:22:31 music-server volumio[594]: info: [1712154151279] [MotherEarth] API delay: 5 Apr 03 09:22:31 music-server volumio[594]: info: Loading plugin "pandora"... Apr 03 09:22:34 music-server volumio[594]: info: Applying required configuration parameters for plugin pandora Apr 03 09:22:34 music-server volumio[594]: info: Loading plugin "personal_radio"... Apr 03 09:22:35 music-server volumio[594]: info: ControllerPersonalRadio::constructor Apr 03 09:22:35 music-server volumio[594]: info: Loading plugin "podcast"... Apr 03 09:22:36 music-server volumio[594]: info: ControllerPodcast::constructor Apr 03 09:22:36 music-server volumio[594]: info: Loading plugin "rad357pl"... Apr 03 09:22:37 music-server volumio[594]: info: Applying required configuration parameters for plugin rad357pl Apr 03 09:22:37 music-server volumio[594]: info: [1712154157425] [rad357pl] API delay: 5 Apr 03 09:22:37 music-server volumio[594]: info: Loading plugin "radio_paradise"... Apr 03 09:22:38 music-server volumio[594]: info: Applying required configuration parameters for plugin radio_paradise Apr 03 09:22:38 music-server volumio[594]: info: [1712154158040] [RadioParadise] API delay: 5 Apr 03 09:22:38 music-server volumio[594]: info: Loading plugin "Systeminfo"... Apr 03 09:22:38 music-server volumio[594]: info: Plugin randomizer is not enabled Apr 03 09:22:38 music-server volumio[594]: info: Loading i18n strings for locale en Apr 03 09:22:39 music-server volumio[594]: Updating browse sources language Apr 03 09:22:39 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:22:39 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 03 09:22:39 music-server volumio[594]: info: CoreCommandRouter::initPlayerControls Apr 03 09:22:39 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:22:39 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:22:39 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:22:39 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:22:39 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:22:39 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:22:39 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:22:39 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:22:39 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 03 09:22:39 music-server volumio[594]: Express server listening on port 3000 Apr 03 09:22:39 music-server volumio[594]: [Metrics] WebUI: 44s 301.18ms Apr 03 09:22:39 music-server volumio[594]: info: CoreStateMachine::resetVolumioState Apr 03 09:22:39 music-server volumio[594]: info: CoreStateMachine::getcurrentVolume Apr 03 09:22:39 music-server volumio[594]: info: CoreCommandRouter::volumioRetrievevolume Apr 03 09:22:39 music-server sudo[761]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Apr 03 09:22:39 music-server sudo[761]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:22:39 music-server sudo[761]: pam_unix(sudo:session): session closed for user root Apr 03 09:22:39 music-server sudo[764]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Apr 03 09:22:39 music-server sudo[764]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:22:39 music-server sudo[764]: pam_unix(sudo:session): session closed for user root Apr 03 09:22:40 music-server volumio[594]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan Apr 03 09:22:40 music-server volumio[594]: wlan0 Interface doesn't support scanning. Apr 03 09:22:40 music-server volumio[594]: info: Cannot use regular scanning, forcing with ap-force Apr 03 09:22:40 music-server sudo[770]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force Apr 03 09:22:40 music-server sudo[770]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:22:40 music-server sudo[770]: pam_unix(sudo:session): session closed for user root Apr 03 09:22:40 music-server volumio[594]: command failed: No such device (-19) Apr 03 09:22:40 music-server volumio[594]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force Apr 03 09:22:40 music-server volumio[594]: command failed: No such device (-19) Apr 03 09:22:40 music-server volumio[594]: verbose: New Socket.io Connection to 192.168.1.246 from 192.168.1.228 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:124.0) Gecko/20100101 Firefox/124.0 Total Clients: 1 Apr 03 09:22:40 music-server volumio[594]: verbose: New Socket.io Connection to 192.168.1.246 from 192.168.1.228 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:124.0) Gecko/20100101 Firefox/124.0 Total Clients: 2 Apr 03 09:22:40 music-server volumio[594]: verbose: New Socket.io Connection to 192.168.1.246 from 192.168.1.228 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:124.0) Gecko/20100101 Firefox/124.0 Total Clients: 3 Apr 03 09:22:40 music-server volumio[594]: verbose: New Socket.io Connection to 192.168.1.246 from 192.168.1.228 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:124.0) Gecko/20100101 Firefox/124.0 Total Clients: 4 Apr 03 09:22:40 music-server volumio[594]: verbose: New Socket.io Connection to 192.168.1.246 from 192.168.1.228 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:124.0) Gecko/20100101 Firefox/124.0 Total Clients: 5 Apr 03 09:22:40 music-server volumio[594]: verbose: New Socket.io Connection to 192.168.1.246 from 192.168.1.228 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:124.0) Gecko/20100101 Firefox/124.0 Total Clients: 6 Apr 03 09:22:40 music-server volumio[594]: info: VolumeController:: Volume=100 Mute =false Apr 03 09:22:40 music-server volumio[594]: info: CoreStateMachine::pushState Apr 03 09:22:40 music-server volumio[594]: info: CorePlayQueue::getTrack 0 Apr 03 09:22:40 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 09:22:40 music-server volumio[594]: info: CoreCommandRouter::volumioPushState Apr 03 09:22:40 music-server volumio[594]: info: CoreStateMachine::updateTrackBlock Apr 03 09:22:40 music-server volumio[594]: info: CorePlayQueue::getTrackBlock Apr 03 09:22:40 music-server volumio[594]: info: CoreCommandRouter::volumioRetrievevolume Apr 03 09:22:40 music-server volumio[594]: info: CoreCommandRouter::volumioGetState Apr 03 09:22:40 music-server volumio[594]: info: CorePlayQueue::getTrack 0 Apr 03 09:22:40 music-server volumio[594]: verbose: New Socket.io Connection to 192.168.1.246 from 192.168.1.228 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:124.0) Gecko/20100101 Firefox/124.0 Total Clients: 7 Apr 03 09:22:40 music-server volumio[594]: verbose: New Socket.io Connection to 192.168.1.246 from 192.168.1.228 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:124.0) Gecko/20100101 Firefox/124.0 Total Clients: 8 Apr 03 09:22:40 music-server volumio[594]: verbose: New Socket.io Connection to 192.168.1.246 from 192.168.1.228 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:124.0) Gecko/20100101 Firefox/124.0 Total Clients: 9 Apr 03 09:22:40 music-server volumio[594]: verbose: New Socket.io Connection to 192.168.1.246 from 192.168.1.228 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:124.0) Gecko/20100101 Firefox/124.0 Total Clients: 10 Apr 03 09:22:40 music-server volumio[594]: verbose: New Socket.io Connection to 192.168.1.246 from 192.168.1.228 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:124.0) Gecko/20100101 Firefox/124.0 Total Clients: 11 Apr 03 09:22:40 music-server volumio[594]: verbose: New Socket.io Connection to 192.168.1.246 from 192.168.1.228 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:124.0) Gecko/20100101 Firefox/124.0 Total Clients: 12 Apr 03 09:22:40 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 03 09:22:40 music-server volumio[594]: info: Reloading queue from file Apr 03 09:22:40 music-server volumio[594]: verbose: New Socket.io Connection to 192.168.1.246 from 192.168.1.228 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:124.0) Gecko/20100101 Firefox/124.0 Total Clients: 13 Apr 03 09:22:40 music-server volumio[594]: info: CoreStateMachine::setRepeat null single undefined Apr 03 09:22:40 music-server volumio[594]: info: CoreStateMachine::pushState Apr 03 09:22:40 music-server volumio[594]: info: CorePlayQueue::getTrack 0 Apr 03 09:22:40 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 03 09:22:40 music-server volumio[594]: info: CoreCommandRouter::volumioPushState Apr 03 09:22:40 music-server volumio[594]: info: CoreStateMachine::setRandom null Apr 03 09:22:40 music-server volumio[594]: info: CoreStateMachine::pushState Apr 03 09:22:40 music-server volumio[594]: info: CorePlayQueue::getTrack 0 Apr 03 09:22:40 music-server volumio[594]: info: CoreCommandRouter::volumioPushState Apr 03 09:22:40 music-server volumio[594]: info: Setting Device type: Raspberry PI Apr 03 09:22:40 music-server volumio[594]: info: Listing playlists Apr 03 09:22:40 music-server volumio[594]: info: Listing playlists Apr 03 09:22:41 music-server volumio[594]: info: VolumeController:: Volume=100 Mute =false Apr 03 09:22:41 music-server volumio[594]: info: CoreStateMachine::pushState Apr 03 09:22:41 music-server volumio[594]: info: CorePlayQueue::getTrack 0 Apr 03 09:22:41 music-server volumio[594]: info: CoreCommandRouter::volumioPushState Apr 03 09:22:41 music-server sudo[782]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Apr 03 09:22:41 music-server sudo[782]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:22:41 music-server volumio[594]: info: Discovery: Browse raised the following error Error: getaddrinfo -3007 Apr 03 09:22:41 music-server systemd[1]: Started UPnP Renderer front-end to MPD. Apr 03 09:22:41 music-server sudo[782]: pam_unix(sudo:session): session closed for user root Apr 03 09:22:41 music-server volumio[594]: info: Upmpdcli Daemon Started Apr 03 09:22:41 music-server volumio[594]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Apr 03 09:22:45 music-server volumio[594]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Apr 03 09:22:45 music-server volumio[594]: verbose: New Socket.io Connection to 192.168.1.246 from 192.168.1.228 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:124.0) Gecko/20100101 Firefox/124.0 Total Clients: 14 Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Apr 03 09:22:45 music-server volumio[594]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Apr 03 09:22:45 music-server volumio[594]: info: Received Get System Version Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 03 09:22:45 music-server volumio[594]: info: Received Get System Info Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 03 09:22:45 music-server volumio[594]: info: Discovery: Getting this device information Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::volumioGetState Apr 03 09:22:45 music-server volumio[594]: info: CorePlayQueue::getTrack 0 Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::volumioGetVisibleSources Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::volumioGetState Apr 03 09:22:45 music-server volumio[594]: info: CorePlayQueue::getTrack 0 Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::volumioGetState Apr 03 09:22:45 music-server volumio[594]: info: CorePlayQueue::getTrack 0 Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::volumioGetQueue Apr 03 09:22:45 music-server volumio[594]: info: CoreStateMachine::getQueue Apr 03 09:22:45 music-server volumio[594]: info: CorePlayQueue::getQueue Apr 03 09:22:45 music-server volumio[594]: info: Listing playlists Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Apr 03 09:22:45 music-server volumio[594]: info: Received Get System Info Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Apr 03 09:22:45 music-server volumio[594]: info: Discovery: Getting this device information Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::volumioGetState Apr 03 09:22:45 music-server volumio[594]: info: CorePlayQueue::getTrack 0 Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 03 09:22:45 music-server volumio[594]: info: CoreCommandRouter::volumioGetState Apr 03 09:22:45 music-server volumio[594]: info: CorePlayQueue::getTrack 0 Apr 03 09:22:46 music-server volumio-remote-updater[396]: [2024-04-03 09:22:46] [connect] Successful connection Apr 03 09:22:46 music-server volumio-remote-updater[396]: [2024-04-03 09:22:46] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1712154166 101 Apr 03 09:22:46 music-server volumio[594]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 15 Apr 03 09:22:46 music-server volumio[594]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 03 09:22:46 music-server volumio[594]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 03 09:22:46 music-server volumio[594]: info: CoreCommandRouter::getUIConfigOnPlugin Apr 03 09:22:47 music-server volumiologrotate[389]: ls: cannot access '/var/log/samba/log.wb-MUSIC': No such file or directory Apr 03 09:22:47 music-server volumiologrotate[389]: ls: cannot access 'SERVER': No such file or directory Apr 03 09:22:49 music-server volumio[594]: info: CoreCommandRouter::volumioGetState Apr 03 09:22:49 music-server volumio[594]: info: CorePlayQueue::getTrack 0 Apr 03 09:22:51 music-server volumio[594]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Apr 03 09:22:55 music-server ntpd[546]: Soliciting pool server 192.189.65.187 Apr 03 09:22:55 music-server ntpd[546]: Soliciting pool server 129.250.35.251 Apr 03 09:22:56 music-server ntpd[546]: Soliciting pool server 135.148.100.14 Apr 03 09:22:56 music-server ntpd[546]: Soliciting pool server 155.248.196.28 Apr 03 09:22:57 music-server ntpd[546]: Soliciting pool server 44.31.46.123 Apr 03 09:22:57 music-server ntpd[546]: Soliciting pool server 69.10.223.133 Apr 03 09:22:58 music-server ntpd[546]: Soliciting pool server 73.234.118.31 Apr 03 09:22:58 music-server ntpd[546]: Soliciting pool server 44.190.5.123 Apr 03 09:22:58 music-server ntpd[546]: Soliciting pool server 216.240.36.24 Apr 03 09:22:59 music-server volumio[594]: info: CoreCommandRouter::volumioGetState Apr 03 09:22:59 music-server volumio[594]: info: CorePlayQueue::getTrack 0 Apr 03 09:22:59 music-server volumio[594]: info: Listing playlists Apr 03 09:22:59 music-server volumio[594]: info: Listing playlists Apr 03 09:22:59 music-server ntpd[546]: Soliciting pool server 152.70.159.102 Apr 03 09:22:59 music-server ntpd[546]: Soliciting pool server 50.205.57.38 Apr 03 09:23:00 music-server ntpd[546]: Soliciting pool server 64.79.100.196 Apr 03 09:23:00 music-server ntpd[546]: Soliciting pool server 96.9.224.210 Apr 03 09:23:01 music-server volumio[594]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 Apr 03 09:23:01 music-server ntpd[546]: Soliciting pool server 69.89.207.99 Apr 03 09:23:01 music-server ntpd[546]: Soliciting pool server 108.161.151.187 Apr 03 09:23:02 music-server ntpd[546]: Soliciting pool server 2604:4500:6:26:1c00:94ff:fe00:ee Apr 03 09:23:22 music-server ntpd[546]: receive: Unexpected origin timestamp 0xe9b7e4c6.5766859e does not match aorg 0000000000.00000000 from server@192.189.65.187 xmt 0xe9b7e4da.dddbe3ce Apr 03 09:23:22 music-server ntpd[546]: receive: Unexpected origin timestamp 0xe9b7e4c6.5752bcf4 does not match aorg 0000000000.00000000 from server@152.70.159.102 xmt 0xe9b7e4da.dfa4f42b Apr 03 09:23:22 music-server ntpd[546]: receive: Unexpected origin timestamp 0xe9b7e4c6.57446446 does not match aorg 0000000000.00000000 from server@108.161.151.187 xmt 0xe9b7e4da.e1298924 Apr 03 09:23:22 music-server ntpd[546]: receive: Unexpected origin timestamp 0xe9b7e4c6.5756684d does not match aorg 0000000000.00000000 from server@216.240.36.24 xmt 0xe9b7e4da.e1e338bd Apr 03 09:23:22 music-server ntpd[546]: receive: Unexpected origin timestamp 0xe9b7e4c6.574e278f does not match aorg 0000000000.00000000 from server@50.205.57.38 xmt 0xe9b7e4da.e2985b75 Apr 03 09:23:22 music-server ntpd[546]: receive: Unexpected origin timestamp 0xe9b7e4c6.575a6e84 does not match aorg 0000000000.00000000 from server@44.190.5.123 xmt 0xe9b7e4da.e4c5873a Apr 03 09:23:22 music-server ntpd[546]: receive: Unexpected origin timestamp 0xe9b7e4c6.57607fde does not match aorg 0000000000.00000000 from server@44.31.46.123 xmt 0xe9b7e4da.e4dd3190 Apr 03 09:23:22 music-server ntpd[546]: receive: Unexpected origin timestamp 0xe9b7e4c6.575d6684 does not match aorg 0000000000.00000000 from server@73.234.118.31 xmt 0xe9b7e4da.e507f778 Apr 03 09:23:29 music-server volumio[594]: error: Plugin system_controller system failed to complete 'onVolumioStart' in a timely fashion Apr 03 09:23:29 music-server volumio[594]: info: Preparing to generate the ALSA configuration file Apr 03 09:23:29 music-server volumio[594]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Apr 03 09:23:29 music-server volumio[594]: info: Reading ALSA contributions from plugins. Apr 03 09:23:29 music-server volumio[594]: info: CoreCommandRouter::volumioGetState Apr 03 09:23:29 music-server volumio[594]: info: CorePlayQueue::getTrack 0 Apr 03 09:23:29 music-server volumio[594]: info: Asound.conf file unchanged, so no further update is needed Apr 03 09:23:29 music-server volumio[594]: info: Output device has changed, restarting MPD Apr 03 09:23:29 music-server sudo[824]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 03 09:23:29 music-server sudo[824]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:23:29 music-server volumio[594]: info: Output device has changed, restarting Shairport Sync Apr 03 09:23:29 music-server sudo[824]: pam_unix(sudo:session): session closed for user root Apr 03 09:23:29 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:29 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 03 09:23:29 music-server sudo[827]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 03 09:23:29 music-server sudo[827]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:23:29 music-server volumio[594]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 03 09:23:29 music-server volumio[594]: info: ___________ START PLUGINS ___________ Apr 03 09:23:29 music-server volumio[594]: info: ControllerMpd::onStart: Initializing MPD Apr 03 09:23:29 music-server volumio[594]: info: Creating MPD Configuration file Apr 03 09:23:29 music-server systemd[1]: Listening on mpd.socket. Apr 03 09:23:29 music-server systemd[1]: Starting Music Player Daemon... Apr 03 09:23:29 music-server sudo[834]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 03 09:23:29 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Apr 03 09:23:29 music-server volumio[594]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 09:23:29 music-server sudo[834]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:23:29 music-server volumio[594]: info: [1712154209922] CoreMusicLibrary::Adding element Media Servers Apr 03 09:23:29 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:23:29 music-server sudo[834]: pam_unix(sudo:session): session closed for user root Apr 03 09:23:29 music-server sudo[837]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 03 09:23:29 music-server sudo[837]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:23:29 music-server systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 03 09:23:29 music-server systemd[1]: mpd.service: Succeeded. Apr 03 09:23:30 music-server systemd[1]: Stopped Music Player Daemon. Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:30 music-server systemd[1]: Starting Music Player Daemon... Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 03 09:23:30 music-server volumio[594]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 03 09:23:30 music-server volumio[594]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 09:23:30 music-server volumio[594]: info: [1712154210237] CoreMusicLibrary::Adding element Last_100 Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 09:23:30 music-server volumio[594]: info: [1712154210248] CoreMusicLibrary::Adding element Webradio Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 09:23:30 music-server volumio[594]: info: [1712154210315] CoreMusicLibrary::Adding element Bandcamp Discover Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Bandcamp Discover Apr 03 09:23:30 music-server volumio[594]: info: Adding Calm Radio to Browse Sources Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 09:23:30 music-server volumio[594]: info: [1712154210329] CoreMusicLibrary::Adding element Calm Radio Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Bandcamp Discover Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Calm Radio Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 09:23:30 music-server volumio[594]: info: [1712154210367] CoreMusicLibrary::Adding element Mixcloud Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Bandcamp Discover Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Calm Radio Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Mixcloud Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 09:23:30 music-server volumio[594]: info: [1712154210401] CoreMusicLibrary::Adding element SoundCloud Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Bandcamp Discover Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Calm Radio Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Mixcloud Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source SoundCloud Apr 03 09:23:30 music-server volumio[594]: info: Creating Spotify config file Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 09:23:30 music-server volumio[594]: info: [1712154210471] CoreMusicLibrary::Adding element YouTube2 Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Bandcamp Discover Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Calm Radio Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Mixcloud Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source SoundCloud Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source YouTube2 Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 09:23:30 music-server volumio[594]: info: [1712154210492] CoreMusicLibrary::Adding element YouTube Music Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Bandcamp Discover Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Calm Radio Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Mixcloud Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source SoundCloud Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source YouTube2 Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source YouTube Music Apr 03 09:23:30 music-server volumio[594]: info: [now-playing] ConfigUpdater: config is up to date. Apr 03 09:23:30 music-server volumio[594]: info: Loading i18n strings for locale en Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:30 music-server volumio[594]: info: FusionDsp - mixtype--------------------- Hardware Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 09:23:30 music-server volumio[594]: info: [1712154210644] CoreMusicLibrary::Adding element 80s80s Radio Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Bandcamp Discover Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Calm Radio Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Mixcloud Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source SoundCloud Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source YouTube2 Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source YouTube Music Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source 80s80s Radio Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 09:23:30 music-server volumio[594]: info: [1712154210718] CoreMusicLibrary::Adding element Mother Earth Radio Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Bandcamp Discover Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Calm Radio Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Mixcloud Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source SoundCloud Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source YouTube2 Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source YouTube Music Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source 80s80s Radio Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Mother Earth Radio Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 09:23:30 music-server volumio[594]: info: [1712154210735] CoreMusicLibrary::Adding element Pandora Radio Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Bandcamp Discover Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Calm Radio Apr 03 09:23:30 music-server sudo[848]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Mixcloud Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source SoundCloud Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source YouTube2 Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source YouTube Music Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source 80s80s Radio Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Mother Earth Radio Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Pandora Radio Apr 03 09:23:30 music-server sudo[848]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:23:30 music-server volumio[594]: info: [1712154210747] ControllerPandora::initializeMQTT Apr 03 09:23:30 music-server volumio[594]: info: [1712154210750] [Pandora] initializeMQTT: MQTT is not enabled in Plugin Configuration Apr 03 09:23:30 music-server systemd[1]: Started RoonBridge. Apr 03 09:23:30 music-server sudo[848]: pam_unix(sudo:session): session closed for user root Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 09:23:30 music-server volumio[594]: info: [1712154210988] CoreMusicLibrary::Adding element Personal Radio Apr 03 09:23:30 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Bandcamp Discover Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Calm Radio Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Mixcloud Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source SoundCloud Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source YouTube2 Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source YouTube Music Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source 80s80s Radio Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Mother Earth Radio Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Pandora Radio Apr 03 09:23:30 music-server volumio[594]: Cannot find translation for source Personal Radio Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 09:23:31 music-server volumio[594]: info: [1712154211040] CoreMusicLibrary::Adding element Podcast Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Bandcamp Discover Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Calm Radio Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Mixcloud Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source SoundCloud Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source YouTube2 Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source YouTube Music Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source 80s80s Radio Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Mother Earth Radio Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Pandora Radio Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Personal Radio Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Podcast Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 09:23:31 music-server volumio[594]: info: [1712154211066] CoreMusicLibrary::Adding element RADIO 357 Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Bandcamp Discover Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Calm Radio Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Mixcloud Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source SoundCloud Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source YouTube2 Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source YouTube Music Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source 80s80s Radio Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Mother Earth Radio Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Pandora Radio Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Personal Radio Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Podcast Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source RADIO 357 Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Apr 03 09:23:31 music-server volumio[594]: info: [1712154211106] CoreMusicLibrary::Adding element Radio Paradise Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Bandcamp Discover Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Calm Radio Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Mixcloud Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source SoundCloud Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source YouTube2 Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source YouTube Music Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source 80s80s Radio Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Mother Earth Radio Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Pandora Radio Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Personal Radio Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Podcast Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source RADIO 357 Apr 03 09:23:31 music-server volumio[594]: Cannot find translation for source Radio Paradise Apr 03 09:23:31 music-server volumio[594]: info: Volumio Calling Home Apr 03 09:23:31 music-server volumio[594]: info: Preparing to generate the ALSA configuration file Apr 03 09:23:31 music-server volumio[594]: info: [1712154211396] ControllerPandora::initialSetup Apr 03 09:23:31 music-server volumio[594]: info: [1712154211424] ControllerPandora::PandoraHandler::init Apr 03 09:23:31 music-server volumio[594]: info: [1712154211426] ControllerPandora::PandoraHandler::loadErrorCodes Apr 03 09:23:31 music-server volumio[594]: info: [1712154211473] [Pandora] PandoraHandler::setMaxStationTracks: 16 Apr 03 09:23:31 music-server volumio[594]: info: [1712154211475] [Pandora] PandoraHandler::setBandFilter: bandfilter is empty Apr 03 09:23:31 music-server volumio[594]: info: [1712154211478] ControllerPandora::flushPandora Apr 03 09:23:31 music-server volumio[594]: info: CorePlayQueue::getQueue Apr 03 09:23:31 music-server volumio[594]: info: CorePlayQueue::clearAddPlayQueue Apr 03 09:23:31 music-server volumio[594]: info: CorePlayQueue::saveQueue Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::serviceClearAddPlayTracks Apr 03 09:23:31 music-server volumio[594]: error: WARNING: No clearAddPlayTracks method for service upnp_browser Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::volumioPushQueue Apr 03 09:23:31 music-server volumio[594]: info: [1712154211497] ControllerPandora::validateAndSetAccountOptions Apr 03 09:23:31 music-server volumio[594]: info: [1712154211499] ControllerPandora::PandoraHandler::setAccountOptions Apr 03 09:23:31 music-server volumio[594]: info: [1712154211503] ControllerPandora::flushPandora Apr 03 09:23:31 music-server volumio[594]: info: CorePlayQueue::getQueue Apr 03 09:23:31 music-server volumio[594]: info: CorePlayQueue::clearAddPlayQueue Apr 03 09:23:31 music-server volumio[594]: info: CorePlayQueue::saveQueue Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::serviceClearAddPlayTracks Apr 03 09:23:31 music-server volumio[594]: error: WARNING: No clearAddPlayTracks method for service upnp_browser Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::volumioPushQueue Apr 03 09:23:31 music-server volumio[594]: info: [1712154211520] [Pandora] PreventAuthTimeout::init: Timer loaded Apr 03 09:23:31 music-server volumio[594]: info: [1712154211521] [Pandora] PreventAuthTimeout::init: Interval set to 10800000 ms Apr 03 09:23:31 music-server volumio[594]: info: [1712154211522] [Pandora] PreventAuthTimeout::init: Starting delayed timer after next interval Apr 03 09:23:31 music-server volumio[594]: info: [1712154211524] ControllerPandora::PandoraHandler::pandoraLoginAndGetStations Apr 03 09:23:31 music-server volumio[594]: info: [now-playing] App is listening on port 4004. Apr 03 09:23:31 music-server volumio[594]: warn: [now-playing] MyBackgroundMonitor is now watching /data/INTERNAL/NowPlayingPlugin/My Backgrounds Apr 03 09:23:31 music-server volumio[594]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Apr 03 09:23:31 music-server volumio[594]: info: Reading ALSA contributions from plugins. Apr 03 09:23:31 music-server volumio[594]: info: MPD Permissions set Apr 03 09:23:31 music-server volumio[594]: info: MPD Permissions set Apr 03 09:23:31 music-server volumio[594]: info: Volumio called home Apr 03 09:23:31 music-server volumio[594]: info: Spotify config file written Apr 03 09:23:31 music-server sudo[863]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Apr 03 09:23:31 music-server sudo[863]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:23:31 music-server volumio[594]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 16 Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:31 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:32 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 03 09:23:32 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:32 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:32 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:32 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:32 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:32 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:32 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:32 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:32 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:32 music-server systemd[1]: Started go-librespot Daemon. Apr 03 09:23:32 music-server go-librespot[867]: Librespot-go daemon starting... Apr 03 09:23:32 music-server sudo[863]: pam_unix(sudo:session): session closed for user root Apr 03 09:23:32 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 03 09:23:32 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:32 music-server volumio[594]: info: Starting Shairport Sync Apr 03 09:23:32 music-server volumio[594]: info: Starting Shairport Sync Apr 03 09:23:32 music-server volumio[594]: info: Starting Shairport Sync Apr 03 09:23:32 music-server sudo[882]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 03 09:23:32 music-server sudo[882]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:23:32 music-server go-librespot[867]: time="2024-04-03T09:23:32-05:00" level=info msg="generated new device id: d1b96d033875a5419fb3bd618c4ce4bdd0fe4ca0" Apr 03 09:23:32 music-server systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 03 09:23:32 music-server sudo[884]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 03 09:23:32 music-server systemd[1]: shairport-sync.service: Succeeded. Apr 03 09:23:32 music-server systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 03 09:23:32 music-server sudo[884]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:23:32 music-server volumio[594]: (node:594) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Apr 03 09:23:32 music-server volumio[594]: (Use `node --trace-deprecation ...` to show where the warning was created) Apr 03 09:23:32 music-server volumio[594]: (node:594) [DEP0106] DeprecationWarning: crypto.createDecipher is deprecated. Apr 03 09:23:32 music-server sudo[888]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 03 09:23:32 music-server systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 03 09:23:32 music-server sudo[888]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:23:32 music-server sudo[882]: pam_unix(sudo:session): session closed for user root Apr 03 09:23:32 music-server systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 03 09:23:32 music-server systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Apr 03 09:23:32 music-server systemd[1]: shairport-sync.service: Succeeded. Apr 03 09:23:32 music-server systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 03 09:23:33 music-server systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 03 09:23:33 music-server sudo[884]: pam_unix(sudo:session): session closed for user root Apr 03 09:23:33 music-server systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 03 09:23:33 music-server systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Apr 03 09:23:33 music-server systemd[1]: shairport-sync.service: Succeeded. Apr 03 09:23:33 music-server systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 03 09:23:33 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:33 music-server systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 03 09:23:33 music-server sudo[888]: pam_unix(sudo:session): session closed for user root Apr 03 09:23:33 music-server volumio[594]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 384000 <-AAAAAAAAAAAAA Apr 03 09:23:33 music-server volumio[594]: info: FusionDsp loaded Apr 03 09:23:33 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 03 09:23:33 music-server sudo[904]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Apr 03 09:23:33 music-server sudo[904]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:23:33 music-server volumio[594]: info: FusionDsp - Reporting Fusion DSP Enabled Apr 03 09:23:33 music-server volumio[594]: info: Adding Signal Path Element [object Object] Apr 03 09:23:33 music-server volumio[594]: info: Adding fusiondspeq DSP Signal Path Element Apr 03 09:23:33 music-server volumio[594]: info: FusionDsp - If filter freq >samplerate/2 then disable it Apr 03 09:23:33 music-server go-librespot[867]: time="2024-04-03T09:23:33-05:00" level=debug msg="fetched new accesspoints: [ap-guc3.spotify.com:4070 ap-guc3.spotify.com:443 ap-guc3.spotify.com:80 ap-gae2.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Apr 03 09:23:33 music-server go-librespot[867]: time="2024-04-03T09:23:33-05:00" level=debug msg="fetched new dealers: [guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Apr 03 09:23:33 music-server go-librespot[867]: time="2024-04-03T09:23:33-05:00" level=debug msg="fetched new spclients: [guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Apr 03 09:23:33 music-server systemd[1]: Started FusionDsp Daemon. Apr 03 09:23:33 music-server go-librespot[867]: time="2024-04-03T09:23:33-05:00" level=debug msg="zeroconf server listening on port 35091" Apr 03 09:23:33 music-server sudo[904]: pam_unix(sudo:session): session closed for user root Apr 03 09:23:34 music-server volumio[594]: info: Shairport-Sync Started Apr 03 09:23:34 music-server volumio[594]: Error adding Membership: Error: addMembership EINVAL Apr 03 09:23:34 music-server volumio[594]: info: Shairport-Sync Started Apr 03 09:23:34 music-server volumio[594]: info: Shairport-Sync Started Apr 03 09:23:34 music-server volumio[594]: info: Asound.conf file unchanged, so no further update is needed Apr 03 09:23:34 music-server volumio[594]: info: Output device has changed, restarting MPD Apr 03 09:23:34 music-server volumio[594]: info: Output device has changed, restarting Shairport Sync Apr 03 09:23:34 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:34 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 03 09:23:34 music-server sudo[911]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Apr 03 09:23:34 music-server sudo[911]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:23:34 music-server sudo[909]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Apr 03 09:23:34 music-server sudo[909]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:23:34 music-server sudo[909]: pam_unix(sudo:session): session closed for user root Apr 03 09:23:34 music-server systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 03 09:23:34 music-server systemd[1]: mpd.service: Succeeded. Apr 03 09:23:34 music-server systemd[1]: Stopped Music Player Daemon. Apr 03 09:23:34 music-server systemd[1]: Starting Music Player Daemon... Apr 03 09:23:34 music-server volumio[594]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Apr 03 09:23:35 music-server RoonBridge[850]: 00:00:00.060 Warn: get lock file path: /tmp/.rnbgem0- Apr 03 09:23:36 music-server volumio[594]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 17 Apr 03 09:23:36 music-server volumio[594]: info: MPD Permissions set Apr 03 09:23:36 music-server volumio[594]: info: go-librespot daemon successfully initialized Apr 03 09:23:36 music-server volumio[594]: info: CoreCommandRouter::volumioGetState Apr 03 09:23:36 music-server volumio[594]: info: CorePlayQueue::getTrack 0 Apr 03 09:23:36 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:36 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:36 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:36 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:36 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:36 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:36 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:36 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:36 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 03 09:23:36 music-server volumio[594]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 03 09:23:36 music-server volumio[594]: info: [1712154216402] [Pandora] PandoraHandler::pandoraLoginAndGetStations::pandoraLogin: [<=- Logged in to Pandora Servers -=>] Apr 03 09:23:36 music-server volumio[594]: info: [1712154216418] [Pandora] validateAndSetAccountOptions: ***DEBUG*** self.loggedIn: true Apr 03 09:23:36 music-server volumio[594]: info: [1712154216423] [Pandora] ExpireOldTracks::init: Timer loaded Apr 03 09:23:36 music-server volumio[594]: info: [1712154216424] [Pandora] ExpireOldTracks::init: Interval set to 300000 ms Apr 03 09:23:36 music-server volumio[594]: info: [1712154216425] [Pandora] ExpireOldTracks::init: Starting delayed timer after next interval Apr 03 09:23:36 music-server volumio[594]: info: [1712154216428] ControllerPandora::PandoraHandler::fillStationData Apr 03 09:23:36 music-server volumio[594]: info: Starting Shairport Sync Apr 03 09:23:36 music-server RoonBridge[850]: 00:00:01.715 Trace: [childprocess] using unix child process Apr 03 09:23:36 music-server sudo[923]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Apr 03 09:23:36 music-server sudo[923]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 03 09:23:36 music-server go-librespot[867]: time="2024-04-03T09:23:36-05:00" level=debug msg="obtained new client token: AACvAduN8KGx1MMyXE4eZYZgSpYszviOajhZlZGB82KmDVMlZOnCuMT/kDhKlRxIkexYkMPqKGvOtMdUgsJ2OtCGrh7SwQK4ZXAsw2Zax+BpgnViqMl5tzbPp6jN73hvYgsX1TwEz5f8BQEmcLQUckX98m1GxLHQ71/bGN4BW7cHV6PxKXKyoGHjwlLndBmLZ29AVpAu5vLNiHgTj4Tfn1n72+Qm9+spP4TTv2QoRqQcdYqF7QdBZJKGEtPK" Apr 03 09:23:36 music-server systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Apr 03 09:23:36 music-server systemd[1]: shairport-sync.service: Succeeded. Apr 03 09:23:36 music-server systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Apr 03 09:23:36 music-server RoonBridge[850]: 00:00:02.058 Debug: PathForResource, filename: ../.update Apr 03 09:23:36 music-server systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Apr 03 09:23:36 music-server sudo[923]: pam_unix(sudo:session): session closed for user root Apr 03 09:23:36 music-server go-librespot[867]: time="2024-04-03T09:23:36-05:00" level=debug msg="completed keyexchange" Apr 03 09:23:36 music-server volumio[594]: info: Shairport-Sync Started Apr 03 09:23:37 music-server volumio[594]: info: FusionDsp - eq1: Apr 03 09:23:37 music-server volumio[594]: type: Biquad Apr 03 09:23:37 music-server volumio[594]: parameters: Apr 03 09:23:37 music-server volumio[594]: type: Peaking Apr 03 09:23:37 music-server volumio[594]: freq: 25 Apr 03 09:23:37 music-server volumio[594]: q: 1.85 Apr 03 09:23:37 music-server volumio[594]: gain: 0 Apr 03 09:23:37 music-server volumio[594]: eq2: Apr 03 09:23:37 music-server volumio[594]: type: Biquad Apr 03 09:23:37 music-server volumio[594]: parameters: Apr 03 09:23:37 music-server volumio[594]: type: Peaking Apr 03 09:23:37 music-server volumio[594]: freq: 40 Apr 03 09:23:37 music-server volumio[594]: q: 1.85 Apr 03 09:23:37 music-server volumio[594]: gain: 0 Apr 03 09:23:37 music-server volumio[594]: eq3: Apr 03 09:23:37 music-server volumio[594]: type: Biquad Apr 03 09:23:37 music-server volumio[594]: parameters: Apr 03 09:23:37 music-server volumio[594]: type: Peaking Apr 03 09:23:37 music-server volumio[594]: freq: 63 Apr 03 09:23:37 music-server volumio[594]: q: 1.85 Apr 03 09:23:37 music-server volumio[594]: gain: 0 Apr 03 09:23:37 music-server volumio[594]: eq4: Apr 03 09:23:37 music-server volumio[594]: type: Biquad Apr 03 09:23:37 music-server volumio[594]: parameters: Apr 03 09:23:37 music-server volumio[594]: type: Peaking Apr 03 09:23:37 music-server volumio[594]: freq: 100 Apr 03 09:23:37 music-server volumio[594]: q: 1.85 Apr 03 09:23:37 music-server volumio[594]: gain: 0 Apr 03 09:23:37 music-server volumio[594]: eq5: Apr 03 09:23:37 music-server volumio[594]: type: Biquad Apr 03 09:23:37 music-server volumio[594]: parameters: Apr 03 09:23:37 music-server volumio[594]: type: Peaking Apr 03 09:23:37 music-server volumio[594]: freq: 160 Apr 03 09:23:37 music-server volumio[594]: q: 1.85 Apr 03 09:23:37 music-server volumio[594]: gain: 0 Apr 03 09:23:37 music-server volumio[594]: eq6: Apr 03 09:23:37 music-server volumio[594]: type: Biquad Apr 03 09:23:37 music-server volumio[594]: parameters: Apr 03 09:23:37 music-server volumio[594]: type: Peaking Apr 03 09:23:37 music-server volumio[594]: freq: 250 Apr 03 09:23:37 music-server volumio[594]: q: 1.85 Apr 03 09:23:37 music-server volumio[594]: gain: 0 Apr 03 09:23:37 music-server volumio[594]: eq7: Apr 03 09:23:37 music-server volumio[594]: type: Biquad Apr 03 09:23:37 music-server volumio[594]: parameters: Apr 03 09:23:37 music-server volumio[594]: type: Peaking Apr 03 09:23:37 music-server volumio[594]: freq: 400 Apr 03 09:23:37 music-server volumio[594]: q: 1.85 Apr 03 09:23:37 music-server volumio[594]: gain: 0 Apr 03 09:23:37 music-server volumio[594]: eq8: Apr 03 09:23:37 music-server volumio[594]: type: Biquad Apr 03 09:23:37 music-server volumio[594]: parameters: Apr 03 09:23:37 music-server volumio[594]: type: Peaking Apr 03 09:23:37 music-server volumio[594]: freq: 630 Apr 03 09:23:37 music-server volumio[594]: q: 1.85 Apr 03 09:23:37 music-server volumio[594]: gain: 0 Apr 03 09:23:37 music-server volumio[594]: eq9: Apr 03 09:23:37 music-server volumio[594]: type: Biquad Apr 03 09:23:37 music-server volumio[594]: parameters: Apr 03 09:23:37 music-server volumio[594]: type: Peaking Apr 03 09:23:37 music-server volumio[594]: freq: 1000 Apr 03 09:23:37 music-server volumio[594]: q: 1.85 Apr 03 09:23:37 music-server volumio[594]: gain: 0 Apr 03 09:23:37 music-server volumio[594]: eq10: Apr 03 09:23:37 music-server volumio[594]: type: Biquad Apr 03 09:23:37 music-server volumio[594]: parameters: Apr 03 09:23:37 music-server volumio[594]: type: Peaking Apr 03 09:23:37 music-server volumio[594]: freq: 1600 Apr 03 09:23:37 music-server volumio[594]: q: 1.85 Apr 03 09:23:37 music-server volumio[594]: gain: 0 Apr 03 09:23:37 music-server volumio[594]: eq11: Apr 03 09:23:37 music-server volumio[594]: type: Biquad Apr 03 09:23:37 music-server volumio[594]: parameters: Apr 03 09:23:37 music-server volumio[594]: type: Peaking Apr 03 09:23:37 music-server volumio[594]: freq: 2500 Apr 03 09:23:37 music-server volumio[594]: q: 1.85 Apr 03 09:23:37 music-server volumio[594]: gain: 0 Apr 03 09:23:37 music-server volumio[594]: eq12: Apr 03 09:23:37 music-server volumio[594]: type: Biquad Apr 03 09:23:37 music-server volumio[594]: parameters: Apr 03 09:23:37 music-server volumio[594]: type: Peaking Apr 03 09:23:37 music-server volumio[594]: freq: 4000 Apr 03 09:23:37 music-server volumio[594]: q: 1.85 Apr 03 09:23:37 music-server volumio[594]: gain: 0 Apr 03 09:23:37 music-server volumio[594]: eq13: Apr 03 09:23:37 music-server volumio[594]: type: Biquad Apr 03 09:23:37 music-server volumio[594]: parameters: Apr 03 09:23:37 music-server volumio[594]: type: Peaking Apr 03 09:23:37 music-server volumio[594]: freq: 6300 Apr 03 09:23:37 music-server volumio[594]: q: 1.85 Apr 03 09:23:37 music-server volumio[594]: gain: 0 Apr 03 09:23:37 music-server volumio[594]: eq14: Apr 03 09:23:37 music-server volumio[594]: type: Biquad Apr 03 09:23:37 music-server volumio[594]: parameters: Apr 03 09:23:37 music-server volumio[594]: type: Peaking Apr 03 09:23:37 music-server volumio[594]: freq: 10000 Apr 03 09:23:37 music-server volumio[594]: q: 1.85 Apr 03 09:23:37 music-server volumio[594]: gain: 0 Apr 03 09:23:37 music-server RoonBridge[850]: 00:00:02.251 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/../.update Apr 03 09:23:37 music-server volumio[594]: error: FusionDsp - WebSocket error: [object Object] Apr 03 09:23:37 music-server RoonBridge[850]: 00:00:02.282 Debug: PathForResource, filename: RAATServer Apr 03 09:23:37 music-server RoonBridge[850]: 00:00:02.283 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer Apr 03 09:23:37 music-server RoonBridge[850]: 00:00:02.285 Debug: PathForResource, filename: RoonBridgeHelper Apr 03 09:23:37 music-server RoonBridge[850]: 00:00:02.286 Debug: PathForResource, candidate: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RoonBridgeHelper Apr 03 09:23:37 music-server RoonBridge[850]: Initializing Apr 03 09:23:37 music-server RoonBridge[850]: 00:00:02.424 Info: Starting /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RoonBridgeHelper Apr 03 09:23:37 music-server RoonBridge[850]: 00:00:02.522 Info: ConnectOrStartAndWaitForExit RAATServer, path: /data/plugins/music_service/RoonBridge/RoonBridge/Bridge/RAATServer Apr 03 09:23:37 music-server go-librespot[867]: time="2024-04-03T09:23:37-05:00" level=debug msg="completed challenge" Apr 03 09:23:37 music-server go-librespot[867]: time="2024-04-03T09:23:37-05:00" level=debug msg="authenticated as burtbartlow" Apr 03 09:23:37 music-server RoonBridge[850]: Not Running (.o) Apr 03 09:23:37 music-server go-librespot[867]: time="2024-04-03T09:23:37-05:00" level=debug msg="authenticated as burtbartlow" Apr 03 09:23:37 music-server mpd[917]: Apr 03 09:23 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Apr 03 09:23:37 music-server go-librespot[867]: time="2024-04-03T09:23:37-05:00" level=debug msg="dealer connection opened" Apr 03 09:23:37 music-server go-librespot[867]: time="2024-04-03T09:23:37-05:00" level=info msg="accepted zeroconf user burtbartlow from Bart's S23+" Apr 03 09:23:37 music-server go-librespot[867]: time="2024-04-03T09:23:37-05:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Apr 03 09:23:37 music-server go-librespot[867]: time="2024-04-03T09:23:37-05:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Apr 03 09:23:37 music-server go-librespot[867]: time="2024-04-03T09:23:37-05:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Apr 03 09:23:37 music-server go-librespot[867]: time="2024-04-03T09:23:37-05:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Apr 03 09:23:37 music-server go-librespot[867]: time="2024-04-03T09:23:37-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Apr 03 09:23:37 music-server go-librespot[867]: time="2024-04-03T09:23:37-05:00" level=debug msg="received connection id: ZjE2NTJmY2EtNDhlNC00MjQwLWIzYWYtZThmY2M2NDcxOWQ3K2RlYWxlcit0Y3A6Ly9ndWMzLWRlYWxlci1hLXhyMnMuZ3VjMy5zcG90aWZ5Lm5ldDo1NzAwK0NCMUUwRUUxM0M4MUE3MUY1RkQ4QzBFNjhFQ0NBQjM3M0NDNzFFQjhEQzFEQzE3M0JEREU5M0M0RERBMTI3QUE=" Apr 03 09:23:37 music-server systemd[1]: Started Music Player Daemon. Apr 03 09:23:37 music-server sudo[827]: pam_unix(sudo:session): session closed for user root Apr 03 09:23:37 music-server sudo[837]: pam_unix(sudo:session): session closed for user root Apr 03 09:23:37 music-server sudo[911]: pam_unix(sudo:session): session closed for user root Apr 03 09:23:38 music-server volumio[594]: info: Completed starting Core Plugins Apr 03 09:23:38 music-server volumio[594]: info: ------------------------------------------- Apr 03 09:23:38 music-server volumio[594]: info: ----- MyVolumio plugins startup ---- Apr 03 09:23:38 music-server volumio[594]: info: ------------------------------------------- Apr 03 09:23:38 music-server volumio[594]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 03 09:23:38 music-server go-librespot[867]: time="2024-04-03T09:23:38-05:00" level=debug msg="put connect state because NEW_DEVICE" Apr 03 09:23:38 music-server volumio[594]: info: MPD running with PID917 Apr 03 09:23:38 music-server volumio[594]: ,establishing connection Apr 03 09:23:38 music-server go-librespot[867]: time="2024-04-03T09:23:38-05:00" level=debug msg="handling transfer player command from 533fedcaf3d547139d12410fe0c08fb0a4e6a673" Apr 03 09:23:38 music-server go-librespot[867]: time="2024-04-03T09:23:38-05:00" level=trace msg="fetched new page 0 with 31 items (list: 31)" Apr 03 09:23:38 music-server go-librespot[867]: time="2024-04-03T09:23:38-05:00" level=debug msg="loading episode spotify:episode:4mma612SsUE5SrUW7bcmIu (paused: false, position: 45679ms)" Apr 03 09:23:38 music-server go-librespot[867]: time="2024-04-03T09:23:38-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 09:23:38 music-server go-librespot[867]: time="2024-04-03T09:23:38-05:00" level=trace msg="emitting websocket event: will_play" Apr 03 09:23:38 music-server volumio[594]: error: MPD error: The expression evaluated to a falsy value: Apr 03 09:23:38 music-server volumio[594]: assert.ok(self.idling) Apr 03 09:23:38 music-server volumio[594]: error: The expression evaluated to a falsy value: Apr 03 09:23:38 music-server volumio[594]: assert.ok(self.idling) Apr 03 09:23:38 music-server go-librespot[867]: time="2024-04-03T09:23:38-05:00" level=debug msg="selected format OGG_VORBIS_96 for spotify:episode:4mma612SsUE5SrUW7bcmIu" Apr 03 09:23:38 music-server go-librespot[867]: time="2024-04-03T09:23:38-05:00" level=debug msg="requested aes key for file 1abfcc732e147e3e1bb8e141daaa7ed300b6654a, gid: 4mma612SsUE5SrUW7bcmIu" Apr 03 09:23:38 music-server volumio[594]: error: MPD error: The expression evaluated to a falsy value: Apr 03 09:23:38 music-server volumio[594]: assert.ok(self.idling) Apr 03 09:23:38 music-server volumio[594]: error: The expression evaluated to a falsy value: Apr 03 09:23:38 music-server volumio[594]: assert.ok(self.idling) Apr 03 09:23:38 music-server volumio[594]: error: MPD error: The expression evaluated to a falsy value: Apr 03 09:23:38 music-server volumio[594]: assert.ok(self.idling) Apr 03 09:23:38 music-server volumio[594]: error: The expression evaluated to a falsy value: Apr 03 09:23:38 music-server volumio[594]: assert.ok(self.idling) Apr 03 09:23:38 music-server volumio[594]: error: updateQueue error: null Apr 03 09:23:38 music-server go-librespot[867]: time="2024-04-03T09:23:38-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1529" Apr 03 09:23:38 music-server go-librespot[867]: time="2024-04-03T09:23:38-05:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1562" Apr 03 09:23:38 music-server go-librespot[867]: time="2024-04-03T09:23:38-05:00" level=debug msg="fetched first chunk of 206, total size is 107975898 bytes" Apr 03 09:23:38 music-server go-librespot[867]: time="2024-04-03T09:23:38-05:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid" Apr 03 09:23:38 music-server go-librespot[867]: time="2024-04-03T09:23:38-05:00" level=trace msg="seek to 45679ms (diff: 832ms, samples: 2014443, bytes: 445452)" Apr 03 09:23:38 music-server RoonBridge[850]: Running Apr 03 09:23:39 music-server volumio[594]: info: Initializing connection to go-librespot Websocket Apr 03 09:23:39 music-server go-librespot[867]: time="2024-04-03T09:23:39-05:00" level=debug msg="new websocket client" Apr 03 09:23:39 music-server volumio[594]: info: Connection to go-librespot Websocket established Apr 03 09:23:39 music-server go-librespot[867]: time="2024-04-03T09:23:39-05:00" level=debug msg="fetched chunk 1/205, size: 524288" Apr 03 09:23:39 music-server go-librespot[867]: time="2024-04-03T09:23:39-05:00" level=info msg="loaded track \"#2128 - Joey Diaz\" (uri: spotify:episode:4mma612SsUE5SrUW7bcmIu, paused: false, position: 45679ms, duration: 10890473ms)" Apr 03 09:23:39 music-server go-librespot[867]: time="2024-04-03T09:23:39-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 09:23:39 music-server go-librespot[867]: time="2024-04-03T09:23:39-05:00" level=trace msg="emitting websocket event: metadata" Apr 03 09:23:39 music-server go-librespot[867]: time="2024-04-03T09:23:39-05:00" level=trace msg="emitting websocket event: active" Apr 03 09:23:39 music-server go-librespot[867]: time="2024-04-03T09:23:39-05:00" level=debug msg="sending successful reply for delaer request" Apr 03 09:23:39 music-server go-librespot[867]: time="2024-04-03T09:23:39-05:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 03 09:23:39 music-server go-librespot[867]: time="2024-04-03T09:23:39-05:00" level=debug msg="fetched chunk 3/205, size: 524288" Apr 03 09:23:39 music-server go-librespot[867]: time="2024-04-03T09:23:39-05:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Apr 03 09:23:39 music-server volumio[594]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:episode:4mma612SsUE5SrUW7bcmIu","name":"#2128 - Joey Diaz","artist_names":["The Joe Rogan Experience"],"album_name":"The Joe Rogan Experience","album_cover_url":"https://i.scdn.co/image/ab6765630000f68d91224a18593bdbf08547280f","position":45679,"duration":10890473,"release_date":"","track_number":0,"disc_number":0}} Apr 03 09:23:39 music-server volumio[594]: SPOTIFY: received: {"type":"active","data":null} Apr 03 09:23:39 music-server volumio[594]: info: Aligning Spotify Volume to Volumio Volume Apr 03 09:23:39 music-server volumio[594]: info: CoreCommandRouter::volumioGetState Apr 03 09:23:39 music-server volumio[594]: info: CorePlayQueue::getTrack 0 Apr 03 09:23:39 music-server volumio[594]: info: Setting Spotify Volume from Volumio: 100 Apr 03 09:23:39 music-server go-librespot[867]: time="2024-04-03T09:23:39-05:00" level=debug msg="fetched chunk 2/205, size: 524288" Apr 03 09:23:39 music-server go-librespot[867]: time="2024-04-03T09:23:39-05:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Apr 03 09:23:39 music-server go-librespot[867]: time="2024-04-03T09:23:39-05:00" level=trace msg="emitting websocket event: playing" Apr 03 09:23:39 music-server volumio[594]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:episode:4mma612SsUE5SrUW7bcmIu","play_origin":"podcast-episode"}} Apr 03 09:23:39 music-server volumio[594]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 09:23:39 music-server volumio[594]: TypeError: Cannot read property 'service' of undefined Apr 03 09:23:39 music-server volumio[594]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Apr 03 09:23:39 music-server volumio[594]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:262:18) Apr 03 09:23:39 music-server volumio[594]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Apr 03 09:23:39 music-server volumio[594]: at WebSocket.emit (events.js:315:20) Apr 03 09:23:39 music-server volumio[594]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1203:20) Apr 03 09:23:39 music-server volumio[594]: at Receiver.emit (events.js:315:20) Apr 03 09:23:39 music-server volumio[594]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:608:16 Apr 03 09:23:39 music-server volumio[594]: at internal/process/task_queues.js:149:7 Apr 03 09:23:39 music-server volumio[594]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) Apr 03 09:23:39 music-server volumio[594]: at AsyncResource.runMicrotask (internal/process/task_queues.js:146:8) Apr 03 09:23:39 music-server volumio[594]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Apr 03 09:23:39 music-server volumio[594]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 03 09:23:40 music-server RoonBridge[850]: 00:00:00.088 Warn: get lock file path: /tmp/.rnbhgem0- Apr 03 09:23:41 music-server sudo[981]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-03 09:22 Apr 03 09:23:41 music-server sudo[981]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"