-- Logs begin at Thu 2024-05-02 10:03:06 JST, end at Thu 2024-05-02 10:06:18 JST. -- May 02 10:05:01 volumio volumio[627]: info: MYVOLUMIO Environment detected May 02 10:05:02 volumio volumio[627]: info: Plugin folders cleanup May 02 10:05:02 volumio volumio[627]: info: Scanning into folder /volumio/app/plugins/ May 02 10:05:02 volumio volumio[627]: info: Scanning category audio_interface May 02 10:05:02 volumio volumio[627]: info: Scanning category miscellanea May 02 10:05:02 volumio volumio[627]: info: Scanning category music_service May 02 10:05:02 volumio volumio[627]: info: Scanning category plugins.json May 02 10:05:02 volumio volumio[627]: info: Scanning category system_controller May 02 10:05:02 volumio volumio[627]: info: Scanning category user_interface May 02 10:05:02 volumio volumio[627]: info: Scanning into folder /data/plugins/ May 02 10:05:02 volumio volumio[627]: info: Plugin folders cleanup completed May 02 10:05:02 volumio volumio[627]: info: ------------------------------------------- May 02 10:05:02 volumio volumio[627]: info: ----- Core plugins startup ---- May 02 10:05:02 volumio volumio[627]: info: ------------------------------------------- May 02 10:05:02 volumio volumio[627]: info: Loading plugins from folder /volumio/app/plugins/ May 02 10:05:02 volumio volumio[627]: info: Adding plugin upnp to MyMusic Plugins May 02 10:05:02 volumio volumio[627]: info: Adding plugin airplay_emulation to MyMusic Plugins May 02 10:05:02 volumio volumio[627]: info: Adding plugin upnp_browser to MyMusic Plugins May 02 10:05:02 volumio volumio[627]: info: Loading plugins from folder /data/plugins/ May 02 10:05:02 volumio volumio[627]: info: Loading plugin "system"... May 02 10:05:02 volumio volumio[627]: info: Loading plugin "appearance"... May 02 10:05:09 volumio volumio-remote-updater[293]: [2024-05-02 10:05:09] [connect] Successful connection May 02 10:05:10 volumio volumio[627]: info: Loading plugin "network"... May 02 10:05:10 volumio volumio[627]: info: Refreshing Cached IP Addresses May 02 10:05:10 volumio volumio[627]: info: Loading plugin "services"... May 02 10:05:10 volumio volumio[627]: info: Loading plugin "alsa_controller"... May 02 10:05:11 volumio sudo[684]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 10:05:11 volumio sudo[682]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 10:05:11 volumio sudo[686]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan May 02 10:05:11 volumio sudo[684]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:05:11 volumio sudo[682]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:05:11 volumio sudo[686]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:05:11 volumio sudo[682]: pam_unix(sudo:session): session closed for user root May 02 10:05:11 volumio sudo[686]: pam_unix(sudo:session): session closed for user root May 02 10:05:11 volumio sudo[684]: pam_unix(sudo:session): session closed for user root May 02 10:05:12 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 02 10:05:12 volumio volumio[627]: info: Loading plugin "wizard"... May 02 10:05:12 volumio volumio[627]: info: Loading plugin "networkfs"... May 02 10:05:12 volumio volumio[627]: info: Starting Udev Watcher for removable devices May 02 10:05:12 volumio sudo[731]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t cifs -o guest,ro,dir_mode=0777,file_mode=0666,iocharset=utf8,noauto,soft //192.168.3.100/Public /mnt/NAS/Public May 02 10:05:12 volumio sudo[731]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:05:13 volumio volumio[627]: info: Ignoring mount for partition: boot May 02 10:05:13 volumio volumio[627]: info: Ignoring mount for partition: volumio May 02 10:05:13 volumio volumio[627]: info: Ignoring mount for partition: volumio_data May 02 10:05:13 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 02 10:05:13 volumio volumio[627]: info: Loading plugin "volumio_command_line_client"... May 02 10:05:13 volumio volumio[627]: info: Loading plugin "upnp"... May 02 10:05:13 volumio volumio[627]: info: [1714611913311] Starting Upmpd Daemon May 02 10:05:13 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 02 10:05:13 volumio volumio[627]: info: Loading plugin "my_music"... May 02 10:05:13 volumio volumio[627]: info: Loading plugin "mpd"... May 02 10:05:14 volumio kernel: Key type cifs.spnego registered May 02 10:05:14 volumio kernel: Key type cifs.idmap registered May 02 10:05:14 volumio kernel: CIFS: No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3.1.1), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3.1.1 (or even SMB3 or SMB2.1) specify vers=1.0 on mount. May 02 10:05:14 volumio kernel: CIFS: Attempting to mount \\192.168.3.100\Public May 02 10:05:15 volumio sudo[731]: pam_unix(sudo:session): session closed for user root May 02 10:05:17 volumio volumio[627]: info: Loading plugin "upnp_browser"... May 02 10:05:19 volumio volumio[627]: info: Loading plugin "alarm-clock"... May 02 10:05:21 volumio volumio[627]: info: Loading plugin "airplay_emulation"... May 02 10:05:21 volumio volumio[627]: info: Starting Shairport Sync May 02 10:05:21 volumio volumio[627]: info: Loading plugin "last_100"... May 02 10:05:21 volumio volumio[627]: info: Loading plugin "webradio"... May 02 10:05:22 volumio volumio[627]: info: Loading plugin "i2s_dacs"... May 02 10:05:22 volumio volumio[627]: info: Loading plugin "volumiodiscovery"... May 02 10:05:22 volumio volumio[627]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 02 10:05:22 volumio node[627]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. May 02 10:05:22 volumio volumio[627]: *** WARNING *** Please fix your application to use the native API of Avahi! May 02 10:05:22 volumio volumio[627]: *** WARNING *** For more information see May 02 10:05:22 volumio volumio[627]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 02 10:05:22 volumio volumio[627]: *** WARNING *** Please fix your application to use the native API of Avahi! May 02 10:05:22 volumio volumio[627]: *** WARNING *** For more information see May 02 10:05:22 volumio node[627]: *** WARNING *** Please fix your application to use the native API of Avahi! May 02 10:05:22 volumio node[627]: *** WARNING *** For more information see May 02 10:05:22 volumio node[627]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. May 02 10:05:22 volumio node[627]: *** WARNING *** Please fix your application to use the native API of Avahi! May 02 10:05:22 volumio node[627]: *** WARNING *** For more information see May 02 10:05:22 volumio volumio[627]: info: Applying required configuration parameters for plugin volumiodiscovery May 02 10:05:22 volumio volumio[627]: info: Discovery: Started advertising with name: Volumio May 02 10:05:22 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 02 10:05:22 volumio volumio[627]: info: Loading plugin "outputs"... May 02 10:05:22 volumio volumio[627]: info: Loading plugin "albumart"... May 02 10:05:22 volumio volumio[627]: info: Plugin example_plugin is not enabled May 02 10:05:22 volumio volumio[627]: info: Loading plugin "inputs"... May 02 10:05:23 volumio volumio[627]: info: Loading plugin "updater_comm"... May 02 10:05:24 volumio volumio-remote-updater[293]: [2024-05-02 10:05:24] [connect] Successful connection May 02 10:05:25 volumio volumio[627]: info: Plugin mpdemulation is not enabled May 02 10:05:25 volumio volumio[627]: info: Loading plugin "rest_api"... May 02 10:05:25 volumio volumio[627]: info: Loading plugin "websocket"... May 02 10:05:25 volumio volumio[627]: info: Loading i18n strings for locale ja May 02 10:05:25 volumio volumio[627]: Updating browse sources language May 02 10:05:26 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 10:05:27 volumio volumio[627]: Forking 1 albumart workers May 02 10:05:28 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 02 10:05:28 volumio volumio[627]: info: CoreCommandRouter::initPlayerControls May 02 10:05:29 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:05:29 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:05:29 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:05:29 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:05:29 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:05:29 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:05:29 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:05:29 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:05:29 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 02 10:05:29 volumio volumio[627]: Express server listening on port 3000 May 02 10:05:29 volumio volumio[627]: [Metrics] WebUI: 37s 757.65ms May 02 10:05:29 volumio volumio[627]: info: CoreStateMachine::resetVolumioState May 02 10:05:29 volumio volumio[627]: info: CoreStateMachine::getcurrentVolume May 02 10:05:29 volumio volumio[627]: info: CoreCommandRouter::volumioRetrievevolume May 02 10:05:30 volumio sudo[791]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 10:05:30 volumio sudo[791]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:05:30 volumio sudo[791]: pam_unix(sudo:session): session closed for user root May 02 10:05:30 volumio sudo[793]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 10:05:30 volumio sudo[793]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:05:30 volumio sudo[793]: pam_unix(sudo:session): session closed for user root May 02 10:05:31 volumio volumio[627]: error: An error occurred while scanning: Error: Command failed: sudo /sbin/iwlist wlan0 scan May 02 10:05:31 volumio volumio[627]: wlan0 Interface doesn't support scanning. May 02 10:05:31 volumio volumio[627]: info: Cannot use regular scanning, forcing with ap-force May 02 10:05:31 volumio sudo[799]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iw dev wlan0 scan ap-force May 02 10:05:31 volumio sudo[799]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:05:31 volumio sudo[799]: pam_unix(sudo:session): session closed for user root May 02 10:05:31 volumio volumio[627]: command failed: No such device (-19) May 02 10:05:31 volumio volumio[627]: error: Cannot use fallback scanning method: Error: Command failed: /usr/bin/sudo /sbin/iw dev wlan0 scan ap-force May 02 10:05:31 volumio volumio[627]: command failed: No such device (-19) May 02 10:05:33 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 10:05:33 volumio volumio[627]: info: Reloading queue from file May 02 10:05:34 volumio volumio[627]: info: VolumeController:: Volume=62 Mute =false May 02 10:05:34 volumio volumio[627]: info: CoreStateMachine::pushState May 02 10:05:34 volumio volumio[627]: info: CorePlayQueue::getTrack 0 May 02 10:05:34 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 02 10:05:34 volumio volumio[627]: info: CoreCommandRouter::volumioPushState May 02 10:05:34 volumio volumio[627]: info: CoreStateMachine::updateTrackBlock May 02 10:05:34 volumio volumio[627]: info: CorePlayQueue::getTrackBlock May 02 10:05:34 volumio volumio[627]: info: CoreCommandRouter::volumioRetrievevolume May 02 10:05:34 volumio volumio[627]: info: CoreStateMachine::setRepeat true single undefined May 02 10:05:34 volumio volumio[627]: info: CoreStateMachine::pushState May 02 10:05:34 volumio volumio[627]: info: CorePlayQueue::getTrack 0 May 02 10:05:34 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 02 10:05:34 volumio volumio[627]: info: CoreCommandRouter::volumioPushState May 02 10:05:34 volumio volumio[627]: info: CoreStateMachine::setRandom null May 02 10:05:34 volumio volumio[627]: info: CoreStateMachine::pushState May 02 10:05:34 volumio volumio[627]: info: CorePlayQueue::getTrack 0 May 02 10:05:34 volumio volumio[627]: info: CoreCommandRouter::volumioPushState May 02 10:05:34 volumio volumio[627]: info: Setting Device type: Raspberry PI May 02 10:05:35 volumio volumio[627]: info: Discovery: adding b1044a6b-1886-41a8-8757-7d15c516a988 May 02 10:05:35 volumio volumio[627]: info: Discovery: Found device Volumio May 02 10:05:35 volumio volumio[627]: info: CoreCommandRouter::volumioGetState May 02 10:05:35 volumio volumio[627]: info: CorePlayQueue::getTrack 0 May 02 10:05:35 volumio sudo[812]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service May 02 10:05:35 volumio sudo[812]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:05:36 volumio systemd[1]: Started UPnP Renderer front-end to MPD. May 02 10:05:36 volumio sudo[812]: pam_unix(sudo:session): session closed for user root May 02 10:05:36 volumio volumio[627]: info: VolumeController:: Volume=62 Mute =false May 02 10:05:36 volumio volumio[627]: info: CoreStateMachine::pushState May 02 10:05:36 volumio volumio[627]: info: CorePlayQueue::getTrack 0 May 02 10:05:36 volumio volumio[627]: info: CoreCommandRouter::volumioPushState May 02 10:05:36 volumio volumio[627]: info: Upmpdcli Daemon Started May 02 10:05:36 volumio volumio[627]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 May 02 10:05:37 volumio sudo[816]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 02 10:05:37 volumio sudo[816]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:05:37 volumio sudo[816]: pam_unix(sudo:session): session closed for user root May 02 10:05:37 volumio sudo[818]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 02 10:05:37 volumio sudo[818]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:05:37 volumio sudo[818]: pam_unix(sudo:session): session closed for user root May 02 10:05:38 volumio volumio[627]: verbose: New Socket.io Connection to 192.168.3.49 from 192.168.3.9 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/124.0.0.0 Safari/537.36 Total Clients: 1 May 02 10:05:38 volumio volumio[627]: Starting albumart workers May 02 10:05:38 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 02 10:05:39 volumio volumio-remote-updater[293]: [2024-05-02 10:05:39] [connect] Successful connection May 02 10:05:39 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 02 10:05:39 volumio volumio[627]: info: CoreCommandRouter::volumioGetVisibleSources May 02 10:05:39 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 10:05:39 volumio volumio[627]: info: CoreCommandRouter::volumioGetState May 02 10:05:39 volumio volumio[627]: info: CorePlayQueue::getTrack 0 May 02 10:05:39 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 02 10:05:39 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 02 10:05:39 volumio volumio[627]: info: Received Get System Info May 02 10:05:39 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 10:05:39 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 10:05:39 volumio volumio[627]: info: Discovery: Getting this device information May 02 10:05:39 volumio volumio[627]: info: CoreCommandRouter::volumioGetState May 02 10:05:39 volumio volumio[627]: info: CorePlayQueue::getTrack 0 May 02 10:05:39 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 10:05:39 volumio volumio[627]: info: CoreCommandRouter::volumioGetState May 02 10:05:39 volumio volumio[627]: info: CorePlayQueue::getTrack 0 May 02 10:05:39 volumio volumio[627]: info: Listing playlists May 02 10:05:39 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 02 10:05:39 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 02 10:05:40 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 02 10:05:40 volumio volumio[627]: info: Received Get System Info May 02 10:05:40 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 10:05:40 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 10:05:40 volumio volumio[627]: info: Discovery: Getting this device information May 02 10:05:40 volumio volumio[627]: info: CoreCommandRouter::volumioGetState May 02 10:05:40 volumio volumio[627]: info: CorePlayQueue::getTrack 0 May 02 10:05:40 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 10:05:40 volumio volumio[627]: info: CoreCommandRouter::volumioGetState May 02 10:05:40 volumio volumio[627]: info: CorePlayQueue::getTrack 0 May 02 10:05:40 volumio volumio-remote-updater[293]: [2024-05-02 10:05:40] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1714611939 101 May 02 10:05:41 volumio volumio[627]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 2 May 02 10:05:41 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 02 10:05:41 volumio volumio[627]: info: Received Get System Info May 02 10:05:41 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 10:05:41 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 10:05:41 volumio volumio[627]: info: Discovery: Getting this device information May 02 10:05:41 volumio volumio[627]: info: CoreCommandRouter::volumioGetState May 02 10:05:41 volumio volumio[627]: info: CorePlayQueue::getTrack 0 May 02 10:05:41 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 10:05:41 volumio volumio[627]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 May 02 10:05:42 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken May 02 10:05:42 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: my_volumio , setMyVolumioToken May 02 10:05:44 volumio volumio[627]: info: CoreCommandRouter::volumioGetQueue May 02 10:05:44 volumio volumio[627]: info: CoreStateMachine::getQueue May 02 10:05:44 volumio volumio[627]: info: CorePlayQueue::getQueue May 02 10:05:46 volumio volumio[627]: error: Upnp client error: Error: connect ECONNREFUSED 127.0.0.1:6600 May 02 10:05:50 volumio volumio[627]: info: Preload queue cleared May 02 10:05:50 volumio volumio[627]: info: CoreCommandRouter::volumioReplaceandPlayItems May 02 10:05:50 volumio volumio[627]: info: CoreStateMachine::ClearQueue May 02 10:05:50 volumio volumio[627]: info: CoreStateMachine::stop May 02 10:05:50 volumio volumio[627]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 10:05:50 volumio volumio[627]: info: CorePlayQueue::clearPlayQueue May 02 10:05:50 volumio volumio[627]: info: CorePlayQueue::saveQueue May 02 10:05:50 volumio volumio[627]: info: CoreCommandRouter::volumioPushQueue May 02 10:05:50 volumio volumio[627]: info: CoreStateMachine::addQueueItems May 02 10:05:50 volumio volumio[627]: info: CorePlayQueue::addQueueItems May 02 10:05:50 volumio volumio[627]: info: Preload queue cleared May 02 10:05:50 volumio volumio[627]: info: Adding Item to queue: upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$0 May 02 10:05:50 volumio volumio[627]: info: Exploding uri upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$0 in service upnp_browser May 02 10:05:50 volumio volumio[627]: info: Adding Item to queue: upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$1 May 02 10:05:50 volumio volumio[627]: info: Exploding uri upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$1 in service upnp_browser May 02 10:05:50 volumio volumio[627]: info: Adding Item to queue: upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$2 May 02 10:05:50 volumio volumio[627]: info: Exploding uri upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$2 in service upnp_browser May 02 10:05:50 volumio volumio[627]: info: Adding Item to queue: upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$3 May 02 10:05:50 volumio volumio[627]: info: Exploding uri upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$3 in service upnp_browser May 02 10:05:50 volumio volumio[627]: info: Adding Item to queue: upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$4 May 02 10:05:50 volumio volumio[627]: info: Exploding uri upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$4 in service upnp_browser May 02 10:05:50 volumio volumio[627]: info: Adding Item to queue: upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$5 May 02 10:05:50 volumio volumio[627]: info: Exploding uri upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$5 in service upnp_browser May 02 10:05:50 volumio volumio[627]: info: Adding Item to queue: upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$6 May 02 10:05:50 volumio volumio[627]: info: Exploding uri upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$6 in service upnp_browser May 02 10:05:50 volumio volumio[627]: info: Adding Item to queue: upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$7 May 02 10:05:50 volumio volumio[627]: info: Exploding uri upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$7 in service upnp_browser May 02 10:05:50 volumio volumio[627]: info: Adding Item to queue: upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$8 May 02 10:05:50 volumio volumio[627]: info: Exploding uri upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$8 in service upnp_browser May 02 10:05:50 volumio volumio[627]: info: Adding Item to queue: upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$9 May 02 10:05:50 volumio volumio[627]: info: Exploding uri upnp/http://192.168.3.100:8200/ctl/ContentDir@1$14$1$20$5$9 in service upnp_browser May 02 10:05:52 volumio volumio[627]: info: CoreCommandRouter::volumioPushQueue May 02 10:05:52 volumio volumio[627]: info: CorePlayQueue::saveQueue May 02 10:05:52 volumio volumio[627]: info: CoreStateMachine::updateTrackBlock May 02 10:05:52 volumio volumio[627]: info: CorePlayQueue::getTrackBlock May 02 10:05:52 volumio volumio[627]: info: CoreCommandRouter::volumioPlay May 02 10:05:52 volumio volumio[627]: info: CoreStateMachine::play index 0 May 02 10:05:52 volumio volumio[627]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 10:05:52 volumio volumio[627]: info: CoreStateMachine::stop May 02 10:05:52 volumio volumio[627]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 10:05:52 volumio volumio[627]: info: CoreStateMachine::play index undefined May 02 10:05:52 volumio volumio[627]: info: CoreStateMachine::setConsumeUpdateService undefined May 02 10:05:52 volumio volumio[627]: info: CorePlayQueue::getTrack 0 May 02 10:05:52 volumio volumio[627]: info: CoreStateMachine::startPlaybackTimer May 02 10:05:52 volumio volumio[627]: info: CorePlayQueue::getTrack 0 May 02 10:05:52 volumio volumio[627]: info: [1714611952714] ControllerUPNPBrowser::clearAddPlayTrack May 02 10:05:55 volumio volumio[627]: error: Plugin system_controller system failed to complete 'onVolumioStart' in a timely fashion May 02 10:05:55 volumio volumio[627]: info: Preparing to generate the ALSA configuration file May 02 10:05:55 volumio volumio[627]: info: Asound.conf file unchanged, so no further update is needed May 02 10:05:55 volumio volumio[627]: info: Output device has changed, restarting MPD May 02 10:05:55 volumio volumio[627]: info: Output device has changed, restarting Shairport Sync May 02 10:05:55 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:05:55 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 10:05:56 volumio sudo[832]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 02 10:05:56 volumio sudo[832]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:05:56 volumio sudo[832]: pam_unix(sudo:session): session closed for user root May 02 10:05:56 volumio sudo[834]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 02 10:05:56 volumio sudo[834]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:05:56 volumio volumio[627]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 02 10:05:56 volumio volumio[627]: info: ___________ START PLUGINS ___________ May 02 10:05:56 volumio systemd[1]: Listening on mpd.socket. May 02 10:05:56 volumio systemd[1]: Starting Music Player Daemon... May 02 10:05:56 volumio volumio[627]: info: ControllerMpd::onStart: Initializing MPD May 02 10:05:56 volumio volumio[627]: info: Creating MPD Configuration file May 02 10:05:56 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 02 10:05:57 volumio volumio[627]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 02 10:05:57 volumio volumio[627]: info: [1714611957054] CoreMusicLibrary::Adding element メディアサーバー May 02 10:05:57 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 10:05:57 volumio sudo[843]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 02 10:05:57 volumio sudo[843]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:05:57 volumio sudo[843]: pam_unix(sudo:session): session closed for user root May 02 10:05:57 volumio sudo[845]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 02 10:05:57 volumio sudo[845]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:05:57 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:05:57 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 10:05:57 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM May 02 10:05:57 volumio systemd[1]: mpd.service: Succeeded. May 02 10:05:57 volumio systemd[1]: Stopped Music Player Daemon. May 02 10:05:58 volumio systemd[1]: Starting Music Player Daemon... May 02 10:05:58 volumio volumio[627]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 02 10:05:58 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:05:58 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 10:05:58 volumio volumio[627]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 02 10:05:58 volumio volumio[627]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 02 10:05:58 volumio volumio[627]: info: [1714611958872] CoreMusicLibrary::Adding element Last_100 May 02 10:05:58 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 10:05:58 volumio volumio[627]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] May 02 10:05:58 volumio volumio[627]: info: [1714611958925] CoreMusicLibrary::Adding element Webradio May 02 10:05:58 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 02 10:05:58 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 02 10:05:59 volumio volumio[627]: info: Volumio Calling Home May 02 10:06:02 volumio volumio[627]: info: MPD Permissions set May 02 10:06:02 volumio volumio[627]: info: MPD Permissions set May 02 10:06:02 volumio volumio[627]: info: Volumio called home May 02 10:06:03 volumio volumio[627]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 3 May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 02 10:06:03 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 02 10:06:06 volumio volumio[627]: info: Starting Shairport Sync May 02 10:06:06 volumio volumio[627]: info: Starting Shairport Sync May 02 10:06:07 volumio volumio[627]: info: Starting Shairport Sync May 02 10:06:07 volumio volumio[627]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 02 10:06:07 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 02 10:06:07 volumio sudo[867]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 02 10:06:07 volumio sudo[867]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:06:07 volumio sudo[869]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 02 10:06:07 volumio sudo[869]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:06:08 volumio sudo[871]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 02 10:06:08 volumio sudo[871]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:06:08 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 02 10:06:08 volumio systemd[1]: shairport-sync.service: Succeeded. May 02 10:06:08 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 02 10:06:08 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 02 10:06:08 volumio sudo[869]: pam_unix(sudo:session): session closed for user root May 02 10:06:08 volumio sudo[867]: pam_unix(sudo:session): session closed for user root May 02 10:06:09 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 02 10:06:09 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM May 02 10:06:09 volumio systemd[1]: shairport-sync.service: Succeeded. May 02 10:06:09 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 02 10:06:09 volumio volumio[627]: info: Shairport-Sync Started May 02 10:06:09 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 02 10:06:09 volumio volumio[627]: Error adding Membership: Error: addMembership EINVAL May 02 10:06:09 volumio volumio[627]: info: Shairport-Sync Started May 02 10:06:09 volumio volumio[627]: info: Received Get System Version May 02 10:06:09 volumio sudo[871]: pam_unix(sudo:session): session closed for user root May 02 10:06:09 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 02 10:06:10 volumio volumio[627]: info: CoreCommandRouter::volumioGetState May 02 10:06:10 volumio volumio[627]: info: CorePlayQueue::getTrack 0 May 02 10:06:10 volumio volumio[627]: info: Shairport-Sync Started May 02 10:06:10 volumio volumio[627]: info: Received Get System Info May 02 10:06:10 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 02 10:06:10 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 02 10:06:10 volumio volumio[627]: info: Discovery: Getting this device information May 02 10:06:10 volumio volumio[627]: info: CoreCommandRouter::volumioGetState May 02 10:06:10 volumio volumio[627]: info: CorePlayQueue::getTrack 0 May 02 10:06:10 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 02 10:06:10 volumio volumio[627]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri May 02 10:06:10 volumio volumio[627]: info: CURURI: albums:// May 02 10:06:10 volumio volumio[627]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 02 10:06:10 volumio volumio[627]: TypeError: Cannot read property 'sendCommand' of undefined May 02 10:06:10 volumio volumio[627]: at /volumio/app/plugins/music_service/mpd/index.js:2986:22 May 02 10:06:10 volumio volumio[627]: at processTicksAndRejections (internal/process/task_queues.js:75:11) May 02 10:06:10 volumio volumio[627]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 02 10:06:18 volumio sudo[923]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-02 10:05 May 02 10:06:18 volumio sudo[923]: pam_unix(sudo:session): session opened for user root by (uid=0) May 02 10:06:18 volumio mpd[849]: May 02 10:06 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 02 10:06:19 volumio systemd[1]: Started Music Player Daemon. May 02 10:06:19 volumio sudo[834]: pam_unix(sudo:session): session closed for user root May 02 10:06:19 volumio sudo[845]: pam_unix(sudo:session): session closed for user root 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"