-- Logs begin at Mon 1980-01-14 06:15:38 CET, end at Tue 1980-01-15 09:59:41 CET. -- Jan 15 09:58:01 volumio volumio[7751]: info: ------------------------------------------- Jan 15 09:58:01 volumio volumio[7751]: info: ----- Volumio3 ---- Jan 15 09:58:01 volumio volumio[7751]: info: ------------------------------------------- Jan 15 09:58:01 volumio volumio[7751]: info: ----- System startup ---- Jan 15 09:58:01 volumio volumio[7751]: info: ------------------------------------------- Jan 15 09:58:02 volumio volumio[7751]: info: MYVOLUMIO Environment detected Jan 15 09:58:02 volumio volumio[7751]: info: Plugin folders cleanup Jan 15 09:58:02 volumio volumio[7751]: info: Scanning into folder /volumio/app/plugins/ Jan 15 09:58:02 volumio volumio[7751]: info: Scanning category audio_interface Jan 15 09:58:02 volumio volumio[7751]: info: Scanning category miscellanea Jan 15 09:58:02 volumio volumio[7751]: info: Scanning category music_service Jan 15 09:58:02 volumio volumio[7751]: info: Scanning category plugins.json Jan 15 09:58:02 volumio volumio[7751]: info: Scanning category system_controller Jan 15 09:58:02 volumio volumio[7751]: info: Scanning category user_interface Jan 15 09:58:02 volumio volumio[7751]: info: Scanning into folder /data/plugins/ Jan 15 09:58:02 volumio volumio[7751]: info: Scanning category audio_interface Jan 15 09:58:02 volumio volumio[7751]: info: Scanning category music_service Jan 15 09:58:02 volumio volumio[7751]: info: Scanning category system_hardware Jan 15 09:58:02 volumio volumio[7751]: info: Plugin folders cleanup completed Jan 15 09:58:02 volumio volumio[7751]: info: ------------------------------------------- Jan 15 09:58:02 volumio volumio[7751]: info: ----- Core plugins startup ---- Jan 15 09:58:02 volumio volumio[7751]: info: ------------------------------------------- Jan 15 09:58:02 volumio volumio[7751]: info: Loading plugins from folder /volumio/app/plugins/ Jan 15 09:58:02 volumio volumio[7751]: info: Adding plugin upnp to MyMusic Plugins Jan 15 09:58:02 volumio volumio[7751]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 15 09:58:02 volumio volumio[7751]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 15 09:58:02 volumio volumio[7751]: info: Loading plugins from folder /data/plugins/ Jan 15 09:58:02 volumio volumio[7751]: info: Loading plugin "system"... Jan 15 09:58:02 volumio volumio[7751]: info: Loading plugin "appearance"... Jan 15 09:58:03 volumio volumio[7751]: info: Loading plugin "network"... Jan 15 09:58:03 volumio volumio[7751]: info: Refreshing Cached IP Addresses Jan 15 09:58:03 volumio sudo[7777]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:03 volumio sudo[7777]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 15 09:58:03 volumio sudo[7777]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:03 volumio sudo[7777]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:03 volumio sudo[7779]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:03 volumio sudo[7779]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 15 09:58:03 volumio sudo[7779]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:03 volumio sudo[7779]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:03 volumio volumio[7751]: info: Loading plugin "services"... Jan 15 09:58:03 volumio volumio[7751]: info: Loading plugin "alsa_controller"... Jan 15 09:58:03 volumio sudo[7788]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:03 volumio sudo[7788]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 15 09:58:03 volumio sudo[7788]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:03 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 15 09:58:03 volumio volumio[7751]: info: Loading plugin "wizard"... Jan 15 09:58:03 volumio volumio[7751]: info: Loading plugin "networkfs"... Jan 15 09:58:03 volumio volumio[7751]: info: Cannot mount NAS pepestore at system boot, trial number 1 ,retrying in 5 seconds Jan 15 09:58:03 volumio volumio[7751]: info: Starting Udev Watcher for removable devices Jan 15 09:58:03 volumio volumio[7751]: info: Ignoring mount for partition: boot Jan 15 09:58:03 volumio volumio[7751]: info: Ignoring mount for partition: volumio Jan 15 09:58:03 volumio volumio[7751]: info: Ignoring mount for partition: volumio_data Jan 15 09:58:03 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 15 09:58:03 volumio volumio[7751]: info: Loading plugin "volumio_command_line_client"... Jan 15 09:58:03 volumio volumio[7751]: info: Loading plugin "upnp"... Jan 15 09:58:03 volumio volumio[7751]: info: [316774683603] Starting Upmpd Daemon Jan 15 09:58:03 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 15 09:58:03 volumio volumio[7751]: info: Loading plugin "my_music"... Jan 15 09:58:03 volumio volumio[7751]: info: Loading plugin "mpd"... Jan 15 09:58:03 volumio volumio[7751]: info: Loading plugin "upnp_browser"... Jan 15 09:58:04 volumio volumio[7751]: info: Loading plugin "alarm-clock"... Jan 15 09:58:04 volumio sudo[7788]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:04 volumio volumio[7751]: info: Plugin airplay_emulation is not enabled Jan 15 09:58:04 volumio volumio[7751]: info: Loading plugin "last_100"... Jan 15 09:58:04 volumio volumio[7751]: info: Loading plugin "webradio"... Jan 15 09:58:04 volumio volumio[7751]: info: Loading plugin "i2s_dacs"... Jan 15 09:58:04 volumio volumio[7751]: info: Loading plugin "volumiodiscovery"... Jan 15 09:58:04 volumio volumio[7751]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 15 09:58:04 volumio volumio[7751]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 15 09:58:04 volumio volumio[7751]: *** WARNING *** For more information see Jan 15 09:58:04 volumio volumio[7751]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 15 09:58:04 volumio node[7751]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 15 09:58:04 volumio volumio[7751]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 15 09:58:04 volumio volumio[7751]: *** WARNING *** For more information see Jan 15 09:58:04 volumio node[7751]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 15 09:58:04 volumio node[7751]: *** WARNING *** For more information see Jan 15 09:58:04 volumio node[7751]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 15 09:58:04 volumio node[7751]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 15 09:58:04 volumio node[7751]: *** WARNING *** For more information see Jan 15 09:58:04 volumio volumio[7751]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 15 09:58:04 volumio volumio[7751]: info: Discovery: Started advertising with name: Volumio Jan 15 09:58:04 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 15 09:58:04 volumio volumio[7751]: info: Loading plugin "ytmusic"... Jan 15 09:58:05 volumio volumio[7751]: info: Loading plugin "outputs"... Jan 15 09:58:05 volumio volumio[7751]: info: Loading plugin "albumart"... Jan 15 09:58:05 volumio volumio[7751]: info: Plugin example_plugin is not enabled Jan 15 09:58:05 volumio volumio[7751]: info: Loading plugin "inputs"... Jan 15 09:58:05 volumio volumio[7751]: info: Loading plugin "updater_comm"... Jan 15 09:58:06 volumio volumio[7751]: info: Plugin mpdemulation is not enabled Jan 15 09:58:06 volumio volumio[7751]: info: Loading plugin "rest_api"... Jan 15 09:58:06 volumio volumio[7751]: info: Loading plugin "websocket"... Jan 15 09:58:06 volumio volumio[7751]: info: Starting Socket.io Server version 2.3.0 Jan 15 09:58:06 volumio volumio[7751]: info: Plugin fusiondsp is not enabled Jan 15 09:58:06 volumio volumio[7751]: info: Plugin ir_controller is not enabled Jan 15 09:58:06 volumio volumio[7751]: info: Loading i18n strings for locale en Jan 15 09:58:06 volumio volumio[7751]: Updating browse sources language Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:58:06 volumio volumio[7751]: Forking 3 albumart workers Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::initPlayerControls Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 09:58:06 volumio volumio[7751]: Express server listening on port 3000 Jan 15 09:58:06 volumio volumio[7751]: [Metrics] WebUI: 5s 492.69ms Jan 15 09:58:06 volumio volumio[7751]: info: CoreStateMachine::resetVolumioState Jan 15 09:58:06 volumio volumio[7751]: info: CoreStateMachine::getcurrentVolume Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::volumioRetrievevolume Jan 15 09:58:06 volumio volumio[7751]: info: Volumio Network Manager: Network status updated: 2 Jan 15 09:58:06 volumio volumio[7751]: verbose: New Socket.io Connection to 10.0.0.31 from 10.0.0.41 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 EdgA/135.0.0.0 Engine version: 3 Transport: polling Total Clients: 1 Jan 15 09:58:06 volumio volumio[7751]: verbose: New Socket.io Connection to 10.0.0.31 from 10.0.0.41 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 EdgA/135.0.0.0 Engine version: 3 Transport: polling Total Clients: 2 Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 15 09:58:06 volumio volumio[7751]: info: Reloading queue from file Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 09:58:06 volumio volumio[7751]: info: CoreStateMachine::setRepeat true single undefined Jan 15 09:58:06 volumio volumio[7751]: info: CoreStateMachine::pushState Jan 15 09:58:06 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:06 volumio volumio[7751]: info: CoreStateMachine::setRandom null Jan 15 09:58:06 volumio volumio[7751]: info: CoreStateMachine::pushState Jan 15 09:58:06 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:06 volumio volumio[7751]: info: Setting Device type: Raspberry PI Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::volumioGetVisibleSources Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::volumioGetState Jan 15 09:58:06 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 15 09:58:06 volumio volumio[7751]: info: Received Get System Info Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 15 09:58:06 volumio volumio[7751]: info: Discovery: Getting this device information Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::volumioGetState Jan 15 09:58:06 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::volumioGetState Jan 15 09:58:06 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:06 volumio volumio[7751]: info: Listing playlists Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::volumioGetQueue Jan 15 09:58:06 volumio volumio[7751]: info: CoreStateMachine::getQueue Jan 15 09:58:06 volumio volumio[7751]: info: CorePlayQueue::getQueue Jan 15 09:58:06 volumio volumio[7751]: info: VolumeController:: Volume=39 Mute =false Jan 15 09:58:06 volumio volumio[7751]: info: CoreStateMachine::pushState Jan 15 09:58:06 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:06 volumio volumio[7751]: info: CoreStateMachine::updateTrackBlock Jan 15 09:58:06 volumio volumio[7751]: info: CorePlayQueue::getTrackBlock Jan 15 09:58:06 volumio volumio[7751]: info: CoreCommandRouter::volumioRetrievevolume Jan 15 09:58:07 volumio volumio[7751]: info: Completed loading Core Plugins Jan 15 09:58:07 volumio volumio[7751]: info: Preparing to generate the ALSA configuration file Jan 15 09:58:07 volumio volumio[7751]: info: VolumeController:: Volume=39 Mute =false Jan 15 09:58:07 volumio volumio[7751]: info: CoreStateMachine::pushState Jan 15 09:58:07 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:07 volumio volumio[7751]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:07 volumio volumio[7751]: info: Asound.conf file unchanged, so no further update is needed Jan 15 09:58:07 volumio volumio[7751]: info: Output device has changed, restarting MPD Jan 15 09:58:07 volumio sudo[7846]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:07 volumio sudo[7846]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 15 09:58:07 volumio sudo[7846]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:07 volumio sudo[7846]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:07 volumio volumio[7751]: info: ___________ START PLUGINS ___________ Jan 15 09:58:07 volumio volumio[7751]: info: ControllerMpd::onStart: Initializing MPD Jan 15 09:58:07 volumio volumio[7751]: info: Creating MPD Configuration file Jan 15 09:58:07 volumio sudo[7849]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:07 volumio sudo[7849]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 15 09:58:07 volumio sudo[7849]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:07 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 09:58:07 volumio volumio[7751]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 15 09:58:07 volumio volumio[7751]: info: [316774687306] CoreMusicLibrary::Adding element Media Servers Jan 15 09:58:07 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:58:07 volumio systemd[1]: Stopping Music Player Daemon... Jan 15 09:58:07 volumio sudo[7851]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:07 volumio sudo[7851]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 15 09:58:07 volumio sudo[7851]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:07 volumio sudo[7851]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:07 volumio sudo[7854]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:07 volumio sudo[7854]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 15 09:58:07 volumio sudo[7854]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:07 volumio systemd[1]: mpd.service: Succeeded. Jan 15 09:58:07 volumio systemd[1]: Stopped Music Player Daemon. Jan 15 09:58:07 volumio volumio[7751]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 15 09:58:07 volumio volumio[7751]: info: [316774687399] CoreMusicLibrary::Adding element Last_100 Jan 15 09:58:07 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:58:07 volumio volumio[7751]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 15 09:58:07 volumio volumio[7751]: info: [316774687406] CoreMusicLibrary::Adding element Webradio Jan 15 09:58:07 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:58:07 volumio volumio[7751]: Starting albumart workers Jan 15 09:58:07 volumio volumio[7751]: Starting albumart workers Jan 15 09:58:07 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 15 09:58:07 volumio volumio[7751]: info: Initializing BBC Radios Jan 15 09:58:07 volumio volumio[7751]: Starting albumart workers Jan 15 09:58:07 volumio systemd[1]: Starting Music Player Daemon... Jan 15 09:58:07 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jan 15 09:58:07 volumio systemd[1]: mpd.service: Succeeded. Jan 15 09:58:07 volumio systemd[1]: Stopped Music Player Daemon. Jan 15 09:58:07 volumio systemd[1]: Starting Music Player Daemon... Jan 15 09:58:07 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 15 09:58:07 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 09:58:07 volumio volumio[7751]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 15 09:58:07 volumio volumio[7751]: info: [316774687590] CoreMusicLibrary::Adding element YouTube Music Jan 15 09:58:07 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:58:07 volumio volumio[7751]: Cannot find translation for source YouTube Music Jan 15 09:58:07 volumio volumio[7751]: info: Volumio Calling Home Jan 15 09:58:07 volumio sudo[7860]: pam_unix(sudo:account): account root has password changed in future Jan 15 09:58:07 volumio sudo[7860]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 15 09:58:07 volumio sudo[7860]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:07 volumio sudo[7860]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:07 volumio volumio[7751]: info: MPD Permissions set Jan 15 09:58:07 volumio volumio[7751]: info: MPD Permissions set Jan 15 09:58:07 volumio volumio[7751]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 15 09:58:07 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:07 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:08 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 09:58:08 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:08 volumio volumio[7751]: info: Volumio called home Jan 15 09:58:08 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:08 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:08 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:08 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:08 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:08 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:08 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:08 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:08 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 09:58:08 volumio volumio[7751]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:08 volumio volumio[7751]: info: CoreCommandRouter::volumioGetState Jan 15 09:58:08 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:08 volumio volumio[7751]: info: Cannot mount NAS pepestore at system boot, trial number 2 ,retrying in 5 seconds Jan 15 09:58:09 volumio volumio[7751]: info: CoreCommandRouter::volumioGetState Jan 15 09:58:09 volumio volumio[7751]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:09 volumio volumio[7751]: info: Listing playlists Jan 15 09:58:09 volumio volumio[7751]: info: Listing playlists Jan 15 09:58:09 volumio mpd[7872]: Jan 15 09:58 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 15 09:58:09 volumio systemd[1]: Started Music Player Daemon. Jan 15 09:58:09 volumio sudo[7849]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:09 volumio sudo[7854]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:09 volumio volumio[7751]: info: Completed starting Core Plugins Jan 15 09:58:09 volumio volumio[7751]: info: ------------------------------------------- Jan 15 09:58:09 volumio volumio[7751]: info: ----- MyVolumio plugins startup ---- Jan 15 09:58:09 volumio volumio[7751]: info: ------------------------------------------- Jan 15 09:58:09 volumio volumio[7751]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 15 09:58:09 volumio volumio[7751]: error: MPD error: The expression evaluated to a falsy value: Jan 15 09:58:09 volumio volumio[7751]: assert.ok(self.idling) Jan 15 09:58:09 volumio volumio[7751]: error: The expression evaluated to a falsy value: Jan 15 09:58:09 volumio volumio[7751]: assert.ok(self.idling) Jan 15 09:58:09 volumio volumio[7751]: error: updateQueue error: null Jan 15 09:58:09 volumio volumio[7751]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 15 09:58:09 volumio volumio[7751]: Error: certificate is not yet valid Jan 15 09:58:09 volumio volumio[7751]: at TLSSocket.onConnectSecure (_tls_wrap.js:1497:34) Jan 15 09:58:09 volumio volumio[7751]: at TLSSocket.emit (events.js:315:20) Jan 15 09:58:09 volumio volumio[7751]: at TLSSocket._finishInit (_tls_wrap.js:932:8) Jan 15 09:58:09 volumio volumio[7751]: at TLSWrap.ssl.onhandshakedone (_tls_wrap.js:706:12) { Jan 15 09:58:09 volumio volumio[7751]: code: 'CERT_NOT_YET_VALID' Jan 15 09:58:09 volumio volumio[7751]: } Jan 15 09:58:09 volumio volumio[7751]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 15 09:58:10 volumio sudo[7919]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:10 volumio sudo[7919]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=1980-01-15 09:57 Jan 15 09:58:10 volumio sudo[7919]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:10 volumio sudo[7919]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:10 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 15 09:58:10 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 15 09:58:10 volumio systemd[1]: Started dynamicswap service. Jan 15 09:58:10 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 15 09:58:10 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jan 15 09:58:10 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 11. Jan 15 09:58:10 volumio systemd[1]: Started dynamicswap service. Jan 15 09:58:10 volumio systemd[1]: Stopped Volumio Backend Module. Jan 15 09:58:10 volumio systemd[1]: Started Volumio Backend Module. Jan 15 09:58:10 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 15 09:58:12 volumio volumio[7930]: info: ------------------------------------------- Jan 15 09:58:12 volumio volumio[7930]: info: ----- Volumio3 ---- Jan 15 09:58:12 volumio volumio[7930]: info: ------------------------------------------- Jan 15 09:58:12 volumio volumio[7930]: info: ----- System startup ---- Jan 15 09:58:12 volumio volumio[7930]: info: ------------------------------------------- Jan 15 09:58:13 volumio volumio[7930]: info: MYVOLUMIO Environment detected Jan 15 09:58:13 volumio volumio[7930]: info: Plugin folders cleanup Jan 15 09:58:13 volumio volumio[7930]: info: Scanning into folder /volumio/app/plugins/ Jan 15 09:58:13 volumio volumio[7930]: info: Scanning category audio_interface Jan 15 09:58:13 volumio volumio[7930]: info: Scanning category miscellanea Jan 15 09:58:13 volumio volumio[7930]: info: Scanning category music_service Jan 15 09:58:13 volumio volumio[7930]: info: Scanning category plugins.json Jan 15 09:58:13 volumio volumio[7930]: info: Scanning category system_controller Jan 15 09:58:13 volumio volumio[7930]: info: Scanning category user_interface Jan 15 09:58:13 volumio volumio[7930]: info: Scanning into folder /data/plugins/ Jan 15 09:58:13 volumio volumio[7930]: info: Scanning category audio_interface Jan 15 09:58:13 volumio volumio[7930]: info: Scanning category music_service Jan 15 09:58:13 volumio volumio[7930]: info: Scanning category system_hardware Jan 15 09:58:13 volumio volumio[7930]: info: Plugin folders cleanup completed Jan 15 09:58:13 volumio volumio[7930]: info: ------------------------------------------- Jan 15 09:58:13 volumio volumio[7930]: info: ----- Core plugins startup ---- Jan 15 09:58:13 volumio volumio[7930]: info: ------------------------------------------- Jan 15 09:58:13 volumio volumio[7930]: info: Loading plugins from folder /volumio/app/plugins/ Jan 15 09:58:13 volumio volumio[7930]: info: Adding plugin upnp to MyMusic Plugins Jan 15 09:58:13 volumio volumio[7930]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 15 09:58:13 volumio volumio[7930]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 15 09:58:13 volumio volumio[7930]: info: Loading plugins from folder /data/plugins/ Jan 15 09:58:13 volumio volumio[7930]: info: Loading plugin "system"... Jan 15 09:58:13 volumio volumio[7930]: info: Loading plugin "appearance"... Jan 15 09:58:14 volumio volumio[7930]: info: Loading plugin "network"... Jan 15 09:58:14 volumio volumio[7930]: info: Refreshing Cached IP Addresses Jan 15 09:58:14 volumio sudo[7956]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:14 volumio sudo[7956]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 15 09:58:14 volumio sudo[7956]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:14 volumio sudo[7956]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:14 volumio sudo[7958]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:14 volumio sudo[7958]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 15 09:58:14 volumio sudo[7958]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:14 volumio sudo[7958]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:14 volumio volumio[7930]: info: Loading plugin "services"... Jan 15 09:58:14 volumio volumio[7930]: info: Loading plugin "alsa_controller"... Jan 15 09:58:14 volumio sudo[7969]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:14 volumio sudo[7969]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 15 09:58:14 volumio sudo[7969]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:14 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 15 09:58:14 volumio volumio[7930]: info: Loading plugin "wizard"... Jan 15 09:58:14 volumio volumio[7930]: info: Loading plugin "networkfs"... Jan 15 09:58:14 volumio volumio[7930]: info: Cannot mount NAS pepestore at system boot, trial number 1 ,retrying in 5 seconds Jan 15 09:58:14 volumio volumio[7930]: info: Starting Udev Watcher for removable devices Jan 15 09:58:14 volumio volumio[7930]: info: Ignoring mount for partition: boot Jan 15 09:58:14 volumio volumio[7930]: info: Ignoring mount for partition: volumio Jan 15 09:58:14 volumio volumio[7930]: info: Ignoring mount for partition: volumio_data Jan 15 09:58:14 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 15 09:58:14 volumio volumio[7930]: info: Loading plugin "volumio_command_line_client"... Jan 15 09:58:14 volumio volumio[7930]: info: Loading plugin "upnp"... Jan 15 09:58:14 volumio volumio[7930]: info: [316774694549] Starting Upmpd Daemon Jan 15 09:58:14 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 15 09:58:14 volumio volumio[7930]: info: Loading plugin "my_music"... Jan 15 09:58:14 volumio volumio[7930]: info: Loading plugin "mpd"... Jan 15 09:58:14 volumio volumio[7930]: info: Loading plugin "upnp_browser"... Jan 15 09:58:15 volumio volumio[7930]: info: Loading plugin "alarm-clock"... Jan 15 09:58:15 volumio sudo[7969]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:15 volumio volumio[7930]: info: Plugin airplay_emulation is not enabled Jan 15 09:58:15 volumio volumio[7930]: info: Loading plugin "last_100"... Jan 15 09:58:15 volumio volumio[7930]: info: Loading plugin "webradio"... Jan 15 09:58:15 volumio volumio[7930]: info: Loading plugin "i2s_dacs"... Jan 15 09:58:15 volumio volumio[7930]: info: Loading plugin "volumiodiscovery"... Jan 15 09:58:15 volumio volumio[7930]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 15 09:58:15 volumio volumio[7930]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 15 09:58:15 volumio volumio[7930]: *** WARNING *** For more information see Jan 15 09:58:15 volumio node[7930]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 15 09:58:15 volumio volumio[7930]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 15 09:58:15 volumio volumio[7930]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 15 09:58:15 volumio volumio[7930]: *** WARNING *** For more information see Jan 15 09:58:15 volumio node[7930]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 15 09:58:15 volumio node[7930]: *** WARNING *** For more information see Jan 15 09:58:15 volumio node[7930]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 15 09:58:15 volumio node[7930]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 15 09:58:15 volumio node[7930]: *** WARNING *** For more information see Jan 15 09:58:15 volumio volumio[7930]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 15 09:58:15 volumio volumio[7930]: info: Discovery: Started advertising with name: Volumio Jan 15 09:58:15 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 15 09:58:15 volumio volumio[7930]: info: Loading plugin "ytmusic"... Jan 15 09:58:16 volumio volumio[7930]: info: Loading plugin "outputs"... Jan 15 09:58:16 volumio volumio[7930]: info: Loading plugin "albumart"... Jan 15 09:58:16 volumio volumio[7930]: info: Plugin example_plugin is not enabled Jan 15 09:58:16 volumio volumio[7930]: info: Loading plugin "inputs"... Jan 15 09:58:16 volumio volumio[7930]: info: Loading plugin "updater_comm"... Jan 15 09:58:17 volumio volumio[7930]: info: Plugin mpdemulation is not enabled Jan 15 09:58:17 volumio volumio[7930]: info: Loading plugin "rest_api"... Jan 15 09:58:17 volumio volumio[7930]: info: Loading plugin "websocket"... Jan 15 09:58:17 volumio volumio[7930]: info: Starting Socket.io Server version 2.3.0 Jan 15 09:58:17 volumio volumio[7930]: info: Plugin fusiondsp is not enabled Jan 15 09:58:17 volumio volumio[7930]: info: Plugin ir_controller is not enabled Jan 15 09:58:17 volumio volumio[7930]: info: Loading i18n strings for locale en Jan 15 09:58:17 volumio volumio[7930]: Updating browse sources language Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:58:17 volumio volumio[7930]: Forking 3 albumart workers Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::initPlayerControls Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 09:58:17 volumio volumio[7930]: Express server listening on port 3000 Jan 15 09:58:17 volumio volumio[7930]: [Metrics] WebUI: 5s 478.19ms Jan 15 09:58:17 volumio volumio[7930]: info: CoreStateMachine::resetVolumioState Jan 15 09:58:17 volumio volumio[7930]: info: CoreStateMachine::getcurrentVolume Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::volumioRetrievevolume Jan 15 09:58:17 volumio volumio[7930]: info: Volumio Network Manager: Network status updated: 2 Jan 15 09:58:17 volumio volumio[7930]: verbose: New Socket.io Connection to 10.0.0.31 from 10.0.0.41 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 EdgA/135.0.0.0 Engine version: 3 Transport: polling Total Clients: 1 Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 09:58:17 volumio volumio[7930]: info: Reloading queue from file Jan 15 09:58:17 volumio volumio[7930]: info: CoreStateMachine::setRepeat true single undefined Jan 15 09:58:17 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:17 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:17 volumio volumio[7930]: info: CoreStateMachine::setRandom null Jan 15 09:58:17 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:17 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:17 volumio volumio[7930]: info: VolumeController:: Volume=39 Mute =false Jan 15 09:58:17 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:17 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:17 volumio volumio[7930]: info: CoreStateMachine::updateTrackBlock Jan 15 09:58:17 volumio volumio[7930]: info: CorePlayQueue::getTrackBlock Jan 15 09:58:17 volumio volumio[7930]: info: CoreCommandRouter::volumioRetrievevolume Jan 15 09:58:17 volumio volumio[7930]: info: Setting Device type: Raspberry PI Jan 15 09:58:17 volumio volumio[7930]: info: Completed loading Core Plugins Jan 15 09:58:17 volumio volumio[7930]: info: Preparing to generate the ALSA configuration file Jan 15 09:58:17 volumio volumio[7930]: info: Asound.conf file unchanged, so no further update is needed Jan 15 09:58:17 volumio volumio[7930]: info: Output device has changed, restarting MPD Jan 15 09:58:17 volumio volumio[7930]: info: ___________ START PLUGINS ___________ Jan 15 09:58:17 volumio sudo[8028]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:17 volumio sudo[8028]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 15 09:58:17 volumio sudo[8028]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:17 volumio volumio[7930]: info: ControllerMpd::onStart: Initializing MPD Jan 15 09:58:17 volumio sudo[8030]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:17 volumio sudo[8030]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 15 09:58:17 volumio sudo[8030]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:17 volumio sudo[8028]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:17 volumio volumio[7930]: info: Creating MPD Configuration file Jan 15 09:58:18 volumio sudo[8034]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:18 volumio sudo[8034]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 15 09:58:18 volumio systemd[1]: Stopping Music Player Daemon... Jan 15 09:58:18 volumio volumio[7930]: info: [316774698014] CoreMusicLibrary::Adding element Media Servers Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:58:18 volumio sudo[8034]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:18 volumio sudo[8034]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:18 volumio sudo[8036]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:18 volumio sudo[8036]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 15 09:58:18 volumio sudo[8036]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:18 volumio systemd[1]: mpd.service: Succeeded. Jan 15 09:58:18 volumio systemd[1]: Stopped Music Player Daemon. Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 15 09:58:18 volumio volumio[7930]: info: [316774698094] CoreMusicLibrary::Adding element Last_100 Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 15 09:58:18 volumio volumio[7930]: info: [316774698099] CoreMusicLibrary::Adding element Webradio Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 15 09:58:18 volumio volumio[7930]: info: Initializing BBC Radios Jan 15 09:58:18 volumio systemd[1]: Starting Music Player Daemon... Jan 15 09:58:18 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Jan 15 09:58:18 volumio systemd[1]: mpd.service: Succeeded. Jan 15 09:58:18 volumio systemd[1]: Stopped Music Player Daemon. Jan 15 09:58:18 volumio systemd[1]: Starting Music Player Daemon... Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 15 09:58:18 volumio volumio[7930]: info: [316774698247] CoreMusicLibrary::Adding element YouTube Music Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:58:18 volumio volumio[7930]: Cannot find translation for source YouTube Music Jan 15 09:58:18 volumio volumio[7930]: info: Volumio Calling Home Jan 15 09:58:18 volumio sudo[8043]: pam_unix(sudo:account): account root has password changed in future Jan 15 09:58:18 volumio sudo[8043]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 15 09:58:18 volumio sudo[8043]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:18 volumio sudo[8043]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:18 volumio volumio[7930]: Starting albumart workers Jan 15 09:58:18 volumio volumio[7930]: verbose: New Socket.io Connection to 10.0.0.31 from 10.0.0.41 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 EdgA/135.0.0.0 Engine version: 3 Transport: polling Total Clients: 2 Jan 15 09:58:18 volumio volumio[7930]: info: MPD Permissions set Jan 15 09:58:18 volumio volumio[7930]: info: MPD Permissions set Jan 15 09:58:18 volumio volumio[7930]: info: VolumeController:: Volume=39 Mute =false Jan 15 09:58:18 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:18 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:18 volumio volumio[7930]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:18 volumio volumio[7930]: Starting albumart workers Jan 15 09:58:18 volumio volumio[7930]: Starting albumart workers Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 09:58:18 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:19 volumio volumio[7930]: info: Volumio called home Jan 15 09:58:19 volumio volumio[7930]: info: CoreCommandRouter::volumioGetState Jan 15 09:58:19 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:19 volumio volumio[7930]: info: CoreCommandRouter::volumioGetState Jan 15 09:58:19 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:19 volumio volumio[7930]: info: Cannot mount NAS pepestore at system boot, trial number 2 ,retrying in 5 seconds Jan 15 09:58:20 volumio mpd[8055]: Jan 15 09:58 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 15 09:58:20 volumio systemd[1]: Started Music Player Daemon. Jan 15 09:58:20 volumio sudo[8036]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:20 volumio sudo[8030]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:20 volumio volumio[7930]: info: Completed starting Core Plugins Jan 15 09:58:20 volumio volumio[7930]: info: ------------------------------------------- Jan 15 09:58:20 volumio volumio[7930]: info: ----- MyVolumio plugins startup ---- Jan 15 09:58:20 volumio volumio[7930]: info: ------------------------------------------- Jan 15 09:58:20 volumio volumio[7930]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 15 09:58:20 volumio volumio[7930]: error: MPD error: The expression evaluated to a falsy value: Jan 15 09:58:20 volumio volumio[7930]: assert.ok(self.idling) Jan 15 09:58:20 volumio volumio[7930]: error: The expression evaluated to a falsy value: Jan 15 09:58:20 volumio volumio[7930]: assert.ok(self.idling) Jan 15 09:58:20 volumio volumio[7930]: info: MPD running with PID8055 Jan 15 09:58:20 volumio volumio[7930]: ,establishing connection Jan 15 09:58:20 volumio volumio[7930]: error: MPD error: The expression evaluated to a falsy value: Jan 15 09:58:20 volumio volumio[7930]: assert.ok(self.idling) Jan 15 09:58:20 volumio volumio[7930]: error: The expression evaluated to a falsy value: Jan 15 09:58:20 volumio volumio[7930]: assert.ok(self.idling) Jan 15 09:58:20 volumio volumio[7930]: error: updateQueue error: null Jan 15 09:58:23 volumio volumio[7930]: verbose: New Socket.io Connection to 10.0.0.31 from 10.0.0.41 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 EdgA/135.0.0.0 Engine version: 3 Transport: polling Total Clients: 4 Jan 15 09:58:23 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 15 09:58:23 volumio volumio[7930]: info: CoreCommandRouter::volumioGetVisibleSources Jan 15 09:58:23 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:58:23 volumio volumio[7930]: info: CoreCommandRouter::volumioGetState Jan 15 09:58:23 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:23 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 15 09:58:23 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 15 09:58:23 volumio volumio[7930]: info: Received Get System Info Jan 15 09:58:23 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 15 09:58:23 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 15 09:58:23 volumio volumio[7930]: info: Discovery: Getting this device information Jan 15 09:58:23 volumio volumio[7930]: info: CoreCommandRouter::volumioGetState Jan 15 09:58:23 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:23 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 15 09:58:23 volumio volumio[7930]: info: CoreCommandRouter::volumioGetState Jan 15 09:58:23 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:23 volumio volumio[7930]: info: Listing playlists Jan 15 09:58:23 volumio volumio[7930]: info: CoreCommandRouter::volumioGetQueue Jan 15 09:58:23 volumio volumio[7930]: info: CoreStateMachine::getQueue Jan 15 09:58:23 volumio volumio[7930]: info: CorePlayQueue::getQueue Jan 15 09:58:24 volumio sudo[8108]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:24 volumio sudo[8108]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 15 09:58:24 volumio sudo[8108]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:24 volumio volumio[7930]: info: Cannot mount NAS pepestore at system boot, trial number 3 ,retrying in 5 seconds Jan 15 09:58:24 volumio sudo[8108]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:24 volumio sudo[8110]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:24 volumio sudo[8110]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 15 09:58:24 volumio sudo[8110]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:24 volumio sudo[8110]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:24 volumio sudo[8114]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:58:24 volumio sudo[8114]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 15 09:58:24 volumio sudo[8114]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:58:24 volumio sudo[8114]: pam_unix(sudo:session): session closed for user root Jan 15 09:58:24 volumio volumio[7930]: info: Upmpdcli Daemon Started Jan 15 09:58:25 volumio volumio[7930]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 15 09:58:27 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 15 09:58:27 volumio volumio[7930]: info: CURURI: albums://Lunz/Lunz%20Reinterpretations Jan 15 09:58:27 volumio volumio[7930]: info: Preload queue cleared Jan 15 09:58:27 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma Jan 15 09:58:27 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/02. Akimbo (The Astrid Kane remix).wma Jan 15 09:58:27 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/03. Lunz (Faultline remix).wma Jan 15 09:58:27 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/04. Wobbly Flu Twilight (''The Chef's Lament'' a Wobbly Flu remix by Elbow).wma Jan 15 09:58:27 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/05. Lunz (Adem's Lunz).wma Jan 15 09:58:27 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/06. Lunz (Ulrich Schnauss remix).wma Jan 15 09:58:27 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/07. Murmerring Mermaids (The Tecil Tempotrope remix by Icarus).wma Jan 15 09:58:27 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/08. Dew Climbs (Half Cousin remix).wma Jan 15 09:58:27 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/09. Wobbly Flu Twilight (Lux Aeterna remix by Alquimia).wma Jan 15 09:58:27 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/10. Carnickel and Pocketboat (Millenia Nova remix).wma Jan 15 09:58:27 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/11. Something Happened Here (Munk interpretation).wma Jan 15 09:58:27 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/12. Under Mars We Were (Arkham remix).wma Jan 15 09:58:27 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma in service mpd Jan 15 09:58:27 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Lunz/Lunz%20Reinterpretations/large&path=%2Fmnt%2FNAS%2Fpepestore%2FLunz%2FLunz%20Reinterpretations%2F01.%20Clue%20(Alias%20remix).wma&metadata=false Jan 15 09:58:27 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma Jan 15 09:58:27 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/02. Akimbo (The Astrid Kane remix).wma in service mpd Jan 15 09:58:27 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Lunz/Lunz%20Reinterpretations/large&path=%2Fmnt%2FNAS%2Fpepestore%2FLunz%2FLunz%20Reinterpretations%2F02.%20Akimbo%20(The%20Astrid%20Kane%20remix).wma&metadata=false Jan 15 09:58:27 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Lunz/Lunz Reinterpretations/02. Akimbo (The Astrid Kane remix).wma Jan 15 09:58:27 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/03. Lunz (Faultline remix).wma in service mpd Jan 15 09:58:27 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Lunz/Lunz%20Reinterpretations/large&path=%2Fmnt%2FNAS%2Fpepestore%2FLunz%2FLunz%20Reinterpretations%2F03.%20Lunz%20(Faultline%20remix).wma&metadata=false Jan 15 09:58:27 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Lunz/Lunz Reinterpretations/03. Lunz (Faultline remix).wma Jan 15 09:58:27 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/04. Wobbly Flu Twilight (''The Chef's Lament'' a Wobbly Flu remix by Elbow).wma in service mpd Jan 15 09:58:27 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Lunz/Lunz%20Reinterpretations/large&path=%2Fmnt%2FNAS%2Fpepestore%2FLunz%2FLunz%20Reinterpretations%2F04.%20Wobbly%20Flu%20Twilight%20(''The%20Chef's%20Lament''%20a%20Wobbly%20Flu%20remix%20by%20Elbow).wma&metadata=false Jan 15 09:58:27 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Lunz/Lunz Reinterpretations/04. Wobbly Flu Twilight (''The Chef's Lament'' a Wobbly Flu remix by Elbow).wma Jan 15 09:58:27 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/05. Lunz (Adem's Lunz).wma in service mpd Jan 15 09:58:27 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Lunz/Lunz%20Reinterpretations/large&path=%2Fmnt%2FNAS%2Fpepestore%2FLunz%2FLunz%20Reinterpretations%2F05.%20Lunz%20(Adem's%20Lunz).wma&metadata=false Jan 15 09:58:27 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Lunz/Lunz Reinterpretations/05. Lunz (Adem's Lunz).wma Jan 15 09:58:27 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/06. Lunz (Ulrich Schnauss remix).wma in service mpd Jan 15 09:58:27 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Lunz/Lunz%20Reinterpretations/large&path=%2Fmnt%2FNAS%2Fpepestore%2FLunz%2FLunz%20Reinterpretations%2F06.%20Lunz%20(Ulrich%20Schnauss%20remix).wma&metadata=false Jan 15 09:58:27 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Lunz/Lunz Reinterpretations/06. Lunz (Ulrich Schnauss remix).wma Jan 15 09:58:27 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/07. Murmerring Mermaids (The Tecil Tempotrope remix by Icarus).wma in service mpd Jan 15 09:58:27 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Lunz/Lunz%20Reinterpretations/large&path=%2Fmnt%2FNAS%2Fpepestore%2FLunz%2FLunz%20Reinterpretations%2F07.%20Murmerring%20Mermaids%20(The%20Tecil%20Tempotrope%20remix%20by%20Icarus).wma&metadata=false Jan 15 09:58:27 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Lunz/Lunz Reinterpretations/07. Murmerring Mermaids (The Tecil Tempotrope remix by Icarus).wma Jan 15 09:58:27 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/08. Dew Climbs (Half Cousin remix).wma in service mpd Jan 15 09:58:27 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Lunz/Lunz%20Reinterpretations/large&path=%2Fmnt%2FNAS%2Fpepestore%2FLunz%2FLunz%20Reinterpretations%2F08.%20Dew%20Climbs%20(Half%20Cousin%20remix).wma&metadata=false Jan 15 09:58:27 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Lunz/Lunz Reinterpretations/08. Dew Climbs (Half Cousin remix).wma Jan 15 09:58:27 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/09. Wobbly Flu Twilight (Lux Aeterna remix by Alquimia).wma in service mpd Jan 15 09:58:28 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Lunz/Lunz%20Reinterpretations/large&path=%2Fmnt%2FNAS%2Fpepestore%2FLunz%2FLunz%20Reinterpretations%2F09.%20Wobbly%20Flu%20Twilight%20(Lux%20Aeterna%20remix%20by%20Alquimia).wma&metadata=false Jan 15 09:58:28 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Lunz/Lunz Reinterpretations/09. Wobbly Flu Twilight (Lux Aeterna remix by Alquimia).wma Jan 15 09:58:28 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/10. Carnickel and Pocketboat (Millenia Nova remix).wma in service mpd Jan 15 09:58:28 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Lunz/Lunz%20Reinterpretations/large&path=%2Fmnt%2FNAS%2Fpepestore%2FLunz%2FLunz%20Reinterpretations%2F10.%20Carnickel%20and%20Pocketboat%20(Millenia%20Nova%20remix).wma&metadata=false Jan 15 09:58:28 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Lunz/Lunz Reinterpretations/10. Carnickel and Pocketboat (Millenia Nova remix).wma Jan 15 09:58:28 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/11. Something Happened Here (Munk interpretation).wma in service mpd Jan 15 09:58:28 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Lunz/Lunz%20Reinterpretations/large&path=%2Fmnt%2FNAS%2Fpepestore%2FLunz%2FLunz%20Reinterpretations%2F11.%20Something%20Happened%20Here%20(Munk%20interpretation).wma&metadata=false Jan 15 09:58:28 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Lunz/Lunz Reinterpretations/11. Something Happened Here (Munk interpretation).wma Jan 15 09:58:28 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/12. Under Mars We Were (Arkham remix).wma in service mpd Jan 15 09:58:28 volumio volumio[7930]: info: No valid Plugin REST Endpoint Jan 15 09:58:28 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Lunz/Lunz%20Reinterpretations/large&path=%2Fmnt%2FNAS%2Fpepestore%2FLunz%2FLunz%20Reinterpretations%2F12.%20Under%20Mars%20We%20Were%20(Arkham%20remix).wma&metadata=false Jan 15 09:58:28 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Lunz/Lunz Reinterpretations/12. Under Mars We Were (Arkham remix).wma Jan 15 09:58:28 volumio volumio[7930]: info: CoreCommandRouter::volumioGetState Jan 15 09:58:28 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:28 volumio volumio[7930]: info: Listing playlists Jan 15 09:58:28 volumio volumio[7930]: info: Listing playlists Jan 15 09:58:29 volumio volumio[7930]: info: Cannot mount NAS pepestore at system boot, trial number 4 ,retrying in 5 seconds Jan 15 09:58:29 volumio volumio[7930]: info: Preload queue cleared Jan 15 09:58:29 volumio volumio[7930]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 15 09:58:29 volumio volumio[7930]: info: CoreStateMachine::ClearQueue Jan 15 09:58:29 volumio volumio[7930]: info: CoreStateMachine::stop Jan 15 09:58:29 volumio volumio[7930]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 09:58:29 volumio volumio[7930]: info: CorePlayQueue::clearPlayQueue Jan 15 09:58:29 volumio volumio[7930]: info: CorePlayQueue::saveQueue Jan 15 09:58:29 volumio volumio[7930]: info: CoreCommandRouter::volumioPushQueue Jan 15 09:58:29 volumio volumio[7930]: info: CoreStateMachine::addQueueItems Jan 15 09:58:29 volumio volumio[7930]: info: CorePlayQueue::addQueueItems Jan 15 09:58:29 volumio volumio[7930]: info: Preload queue cleared Jan 15 09:58:29 volumio volumio[7930]: info: Adding Item to queue: albums://Lunz/Lunz%20Reinterpretations Jan 15 09:58:29 volumio volumio[7930]: info: Exploding uri albums://Lunz/Lunz%20Reinterpretations in service mpd Jan 15 09:58:29 volumio volumio[7930]: info: CoreCommandRouter::volumioPushQueue Jan 15 09:58:29 volumio volumio[7930]: info: CorePlayQueue::saveQueue Jan 15 09:58:29 volumio volumio[7930]: info: CoreStateMachine::updateTrackBlock Jan 15 09:58:29 volumio volumio[7930]: info: CorePlayQueue::getTrackBlock Jan 15 09:58:29 volumio volumio[7930]: info: CoreCommandRouter::volumioPlay Jan 15 09:58:29 volumio volumio[7930]: info: CoreStateMachine::play index 0 Jan 15 09:58:29 volumio volumio[7930]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 09:58:29 volumio volumio[7930]: info: CoreStateMachine::stop Jan 15 09:58:29 volumio volumio[7930]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 09:58:29 volumio volumio[7930]: info: CoreStateMachine::play index undefined Jan 15 09:58:29 volumio volumio[7930]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 09:58:29 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:29 volumio volumio[7930]: info: CoreStateMachine::startPlaybackTimer Jan 15 09:58:29 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:29 volumio volumio[7930]: verbose: ControllerMpd::clearAddPlayTracks NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma Jan 15 09:58:29 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand stop Jan 15 09:58:29 volumio volumio[7930]: info: sendMpdCommand stop took 5 milliseconds Jan 15 09:58:29 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand clear Jan 15 09:58:29 volumio volumio[7930]: info: Jan 15 09:58:29 volumio volumio[7930]: ---------------------------- MPD announces system playlist update Jan 15 09:58:29 volumio volumio[7930]: info: Ignoring MPD Status Update Jan 15 09:58:29 volumio volumio[7930]: info: sendMpdCommand clear took 4 milliseconds Jan 15 09:58:29 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand add "NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma" Jan 15 09:58:29 volumio volumio[7930]: info: Jan 15 09:58:29 volumio volumio[7930]: ---------------------------- MPD announces system playlist update Jan 15 09:58:29 volumio volumio[7930]: info: Ignoring MPD Status Update Jan 15 09:58:29 volumio volumio[7930]: info: Jan 15 09:58:29 volumio volumio[7930]: ---------------------------- MPD announces system playlist update Jan 15 09:58:29 volumio volumio[7930]: info: Ignoring MPD Status Update Jan 15 09:58:29 volumio volumio[7930]: error: updateQueue error: null Jan 15 09:58:29 volumio volumio[7930]: info: Jan 15 09:58:29 volumio volumio[7930]: ---------------------------- MPD announces system playlist update Jan 15 09:58:29 volumio volumio[7930]: info: Ignoring MPD Status Update Jan 15 09:58:29 volumio volumio[7930]: info: ------------------------------ 13ms Jan 15 09:58:29 volumio volumio[7930]: info: sendMpdCommand add "NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma" took 11 milliseconds Jan 15 09:58:29 volumio volumio[7930]: info: ------------------------------ 9ms Jan 15 09:58:29 volumio volumio[7930]: info: ------------------------------ 9ms Jan 15 09:58:29 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand play Jan 15 09:58:29 volumio volumio[7930]: info: Jan 15 09:58:29 volumio volumio[7930]: ---------------------------- MPD announces system playlist update Jan 15 09:58:29 volumio volumio[7930]: info: Ignoring MPD Status Update Jan 15 09:58:29 volumio volumio[7930]: info: Jan 15 09:58:29 volumio volumio[7930]: ---------------------------- MPD announces system playlist update Jan 15 09:58:29 volumio volumio[7930]: info: Ignoring MPD Status Update Jan 15 09:58:29 volumio volumio[7930]: info: ------------------------------ 11ms Jan 15 09:58:29 volumio volumio[7930]: info: sendMpdCommand play took 7 milliseconds Jan 15 09:58:29 volumio volumio[7930]: info: ------------------------------ 7ms Jan 15 09:58:29 volumio volumio[7930]: info: ------------------------------ 7ms Jan 15 09:58:30 volumio volumio[7930]: info: Jan 15 09:58:30 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:30 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:30 volumio volumio[7930]: info: Jan 15 09:58:30 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:30 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:30 volumio volumio[7930]: info: Jan 15 09:58:30 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:30 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:30 volumio volumio[7930]: info: Jan 15 09:58:30 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:30 volumio volumio[7930]: info: sendMpdCommand status took 20 milliseconds Jan 15 09:58:30 volumio volumio[7930]: info: sendMpdCommand status took 19 milliseconds Jan 15 09:58:30 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:30 volumio volumio[7930]: info: sendMpdCommand status took 24 milliseconds Jan 15 09:58:30 volumio volumio[7930]: info: sendMpdCommand status took 10 milliseconds Jan 15 09:58:30 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 8 milliseconds Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:30 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:30 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:30 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"169 Kbps","isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:30 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus stop Jan 15 09:58:30 volumio volumio[7930]: info: ------------------------------ 61ms Jan 15 09:58:30 volumio volumio[7930]: info: Jan 15 09:58:30 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:30 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:30 volumio volumio[7930]: info: Jan 15 09:58:30 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:30 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:30 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 57 milliseconds Jan 15 09:58:30 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 48 milliseconds Jan 15 09:58:30 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 47 milliseconds Jan 15 09:58:30 volumio volumio[7930]: info: sendMpdCommand status took 25 milliseconds Jan 15 09:58:30 volumio volumio[7930]: info: sendMpdCommand status took 10 milliseconds Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:30 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:30 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:30 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":11,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"169 Kbps","isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:30 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus play Jan 15 09:58:30 volumio volumio[7930]: info: Received an update from plugin. extracting info from payload Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:30 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:30 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:30 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:30 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:30 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":57,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"169 Kbps","isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:30 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus play Jan 15 09:58:30 volumio volumio[7930]: info: Received an update from plugin. extracting info from payload Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:30 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:30 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:30 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:30 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:30 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":948,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"169 Kbps","isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:30 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus play Jan 15 09:58:30 volumio volumio[7930]: info: Received an update from plugin. extracting info from payload Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:30 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:30 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:30 volumio volumio[7930]: info: ------------------------------ 160ms Jan 15 09:58:30 volumio volumio[7930]: info: ------------------------------ 158ms Jan 15 09:58:30 volumio volumio[7930]: info: ------------------------------ 146ms Jan 15 09:58:30 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 73 milliseconds Jan 15 09:58:30 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 72 milliseconds Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:30 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:30 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:30 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:30 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":948,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"169 Kbps","isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:30 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus play Jan 15 09:58:30 volumio volumio[7930]: info: Received an update from plugin. extracting info from payload Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:30 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:30 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:30 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:30 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:30 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":948,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"169 Kbps","isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:30 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus play Jan 15 09:58:30 volumio volumio[7930]: info: Received an update from plugin. extracting info from payload Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:30 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:30 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:30 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:30 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:30 volumio volumio[7930]: info: ------------------------------ 158ms Jan 15 09:58:30 volumio volumio[7930]: info: ------------------------------ 156ms Jan 15 09:58:34 volumio volumio[7930]: info: Cannot mount NAS at system boot, trial number 4 ,stopping Jan 15 09:58:37 volumio volumio[7930]: info: Preload queue cleared Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::ClearQueue Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::stop Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::stPlaybackTimer Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::updateTrackBlock Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrackBlock Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::serviceStop Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::serviceStop Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::stop Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand stop Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::clearPlayQueue Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::saveQueue Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushQueue Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::addQueueItems Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::addQueueItems Jan 15 09:58:37 volumio volumio[7930]: info: Preload queue cleared Jan 15 09:58:37 volumio volumio[7930]: info: Adding Item to queue: albums://Lunz/Lunz%20Reinterpretations Jan 15 09:58:37 volumio volumio[7930]: info: Using cached record of: albums://Lunz/Lunz%20Reinterpretations Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushQueue Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::saveQueue Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::updateTrackBlock Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrackBlock Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPlay Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::play index 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::stop Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::play index undefined Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::startPlaybackTimer Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::clearAddPlayTracks NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand stop Jan 15 09:58:37 volumio volumio[7930]: info: Jan 15 09:58:37 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand stop took 25 milliseconds Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand stop took 6 milliseconds Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand clear Jan 15 09:58:37 volumio volumio[7930]: info: Jan 15 09:58:37 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:37 volumio volumio[7930]: info: Jan 15 09:58:37 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:37 volumio volumio[7930]: info: Jan 15 09:58:37 volumio volumio[7930]: ---------------------------- MPD announces system playlist update Jan 15 09:58:37 volumio volumio[7930]: info: Ignoring MPD Status Update Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand status took 7 milliseconds Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand clear took 6 milliseconds Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand status took 5 milliseconds Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand status took 3 milliseconds Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand add "NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma" Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jan 15 09:58:37 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::syncState stateService stop Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus stop Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: No code Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jan 15 09:58:37 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::syncState stateService stop Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus stop Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: No code Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: ------------------------------ 44ms Jan 15 09:58:37 volumio volumio[7930]: info: ------------------------------ 44ms Jan 15 09:58:37 volumio volumio[7930]: info: Jan 15 09:58:37 volumio volumio[7930]: ---------------------------- MPD announces system playlist update Jan 15 09:58:37 volumio volumio[7930]: info: Ignoring MPD Status Update Jan 15 09:58:37 volumio volumio[7930]: info: Jan 15 09:58:37 volumio volumio[7930]: ---------------------------- MPD announces system playlist update Jan 15 09:58:37 volumio volumio[7930]: info: Ignoring MPD Status Update Jan 15 09:58:37 volumio volumio[7930]: error: updateQueue error: null Jan 15 09:58:37 volumio volumio[7930]: info: Jan 15 09:58:37 volumio volumio[7930]: ---------------------------- MPD announces system playlist update Jan 15 09:58:37 volumio volumio[7930]: info: Ignoring MPD Status Update Jan 15 09:58:37 volumio volumio[7930]: info: ------------------------------ 50ms Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 48 milliseconds Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand add "NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma" took 47 milliseconds Jan 15 09:58:37 volumio volumio[7930]: info: ------------------------------ 9ms Jan 15 09:58:37 volumio volumio[7930]: info: ------------------------------ 7ms Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand play Jan 15 09:58:37 volumio volumio[7930]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Jan 15 09:58:37 volumio volumio[7930]: info: ------------------------------ 63ms Jan 15 09:58:37 volumio volumio[7930]: info: Jan 15 09:58:37 volumio volumio[7930]: ---------------------------- MPD announces system playlist update Jan 15 09:58:37 volumio volumio[7930]: info: Ignoring MPD Status Update Jan 15 09:58:37 volumio volumio[7930]: info: Jan 15 09:58:37 volumio volumio[7930]: ---------------------------- MPD announces system playlist update Jan 15 09:58:37 volumio volumio[7930]: info: Ignoring MPD Status Update Jan 15 09:58:37 volumio volumio[7930]: info: ------------------------------ 15ms Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand play took 11 milliseconds Jan 15 09:58:37 volumio volumio[7930]: info: ------------------------------ 9ms Jan 15 09:58:37 volumio volumio[7930]: info: ------------------------------ 9ms Jan 15 09:58:37 volumio volumio[7930]: info: Jan 15 09:58:37 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:37 volumio volumio[7930]: info: Jan 15 09:58:37 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:37 volumio volumio[7930]: info: Jan 15 09:58:37 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:37 volumio volumio[7930]: info: Jan 15 09:58:37 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand status took 8 milliseconds Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand status took 7 milliseconds Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand status took 4 milliseconds Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:37 volumio volumio[7930]: info: Jan 15 09:58:37 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:37 volumio volumio[7930]: info: Jan 15 09:58:37 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand status took 27 milliseconds Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 25 milliseconds Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 24 milliseconds Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 24 milliseconds Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand status took 21 milliseconds Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand status took 18 milliseconds Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:37 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus stop Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:37 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus play Jan 15 09:58:37 volumio volumio[7930]: info: Received an update from plugin. extracting info from payload Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:37 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus play Jan 15 09:58:37 volumio volumio[7930]: info: Received an update from plugin. extracting info from payload Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: ------------------------------ 82ms Jan 15 09:58:37 volumio volumio[7930]: info: ------------------------------ 95ms Jan 15 09:58:37 volumio volumio[7930]: info: ------------------------------ 94ms Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 59 milliseconds Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 55 milliseconds Jan 15 09:58:37 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 54 milliseconds Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:37 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":948,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"169 Kbps","isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:37 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus play Jan 15 09:58:37 volumio volumio[7930]: info: Received an update from plugin. extracting info from payload Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":948,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"169 Kbps","isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:37 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus play Jan 15 09:58:37 volumio volumio[7930]: info: Received an update from plugin. extracting info from payload Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":948,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"169 Kbps","isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:37 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus play Jan 15 09:58:37 volumio volumio[7930]: info: Received an update from plugin. extracting info from payload Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:37 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:37 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:37 volumio volumio[7930]: info: ------------------------------ 136ms Jan 15 09:58:37 volumio volumio[7930]: info: ------------------------------ 127ms Jan 15 09:58:37 volumio volumio[7930]: info: ------------------------------ 124ms Jan 15 09:58:38 volumio volumio[7930]: info: CoreCommandRouter::volumioGetState Jan 15 09:58:38 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:40 volumio volumio[7930]: error: MyVolumio Plugin failed to start in a timely fashion Jan 15 09:58:40 volumio volumio[7930]: [Metrics] CommandRouter: 28s 34.39ms Jan 15 09:58:40 volumio volumio[7930]: info: CoreCommandRouter::volumiosetStartupVolume Jan 15 09:58:40 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:58:40 volumio volumio[7930]: info: VolumeController:: Setting startup Volume 40 Jan 15 09:58:40 volumio volumio[7930]: info: VolumeController::SetAlsaVolume40 Jan 15 09:58:40 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 09:58:40 volumio volumio[7930]: info: CoreCommandRouter::Close All Modals sent Jan 15 09:58:40 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:40 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:40 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:58:40 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:40 volumio volumio[7930]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Jan 15 09:58:40 volumio volumio[7930]: aplay: main:828: audio open error: Device or resource busy Jan 15 09:58:41 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jan 15 09:58:41 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jan 15 09:58:41 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jan 15 09:58:46 volumio volumio[7930]: info: CoreCommandRouter::volumioSeek Jan 15 09:58:46 volumio volumio[7930]: info: CoreStateMachine::seek Jan 15 09:58:46 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:46 volumio volumio[7930]: info: TRACKBLOCK {"uri":"music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","service":"mpd","name":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=876&web=Lunz/Lunz%20Reinterpretations/large&path=%2Fmnt%2FNAS%2Fpepestore%2FLunz%2FLunz%20Reinterpretations&metadata=false","duration":318,"trackType":"wma","samplerate":44.1,"bitdepth":"32 bit","channels":2} Jan 15 09:58:46 volumio volumio[7930]: info: CoreStateMachine::startPlaybackTimer Jan 15 09:58:46 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:46 volumio volumio[7930]: info: ControllerMpd::seek Jan 15 09:58:46 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:46 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:46 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:58:46 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:46 volumio volumio[7930]: error: null Jan 15 09:58:46 volumio volumio[7930]: info: Jan 15 09:58:46 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:46 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:46 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:46 volumio volumio[7930]: info: Jan 15 09:58:46 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:46 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:46 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:46 volumio volumio[7930]: info: Jan 15 09:58:46 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:46 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:46 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:46 volumio volumio[7930]: info: sendMpdCommand status took 11 milliseconds Jan 15 09:58:46 volumio volumio[7930]: info: sendMpdCommand status took 9 milliseconds Jan 15 09:58:46 volumio volumio[7930]: info: sendMpdCommand status took 5 milliseconds Jan 15 09:58:46 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:46 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:46 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:46 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:46 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:46 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:46 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 7 milliseconds Jan 15 09:58:46 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 7 milliseconds Jan 15 09:58:46 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 6 milliseconds Jan 15 09:58:46 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:46 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:46 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:46 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:46 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:46 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:46 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45000,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"169 Kbps","isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:46 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:46 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:46 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus play Jan 15 09:58:46 volumio volumio[7930]: info: Received an update from plugin. extracting info from payload Jan 15 09:58:46 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:46 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:46 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:46 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:46 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:46 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:46 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:46 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:46 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:46 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45000,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"169 Kbps","isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:46 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:46 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:46 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus play Jan 15 09:58:46 volumio volumio[7930]: info: Received an update from plugin. extracting info from payload Jan 15 09:58:46 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:46 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:46 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:46 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:46 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:46 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:46 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:46 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:46 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:46 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":45000,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"169 Kbps","isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:46 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:46 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:46 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus play Jan 15 09:58:46 volumio volumio[7930]: info: Received an update from plugin. extracting info from payload Jan 15 09:58:46 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:46 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:46 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:46 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:46 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:46 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:46 volumio volumio[7930]: info: ------------------------------ 87ms Jan 15 09:58:46 volumio volumio[7930]: info: ------------------------------ 86ms Jan 15 09:58:46 volumio volumio[7930]: info: ------------------------------ 82ms Jan 15 09:58:47 volumio volumio[7930]: info: BOOT COMPLETED Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::volumioSeek Jan 15 09:58:48 volumio volumio[7930]: info: CoreStateMachine::seek Jan 15 09:58:48 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:48 volumio volumio[7930]: info: TRACKBLOCK {"uri":"music-library/NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","service":"mpd","name":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","type":"track","tracknumber":0,"albumart":"/albumart?cacheid=876&web=Lunz/Lunz%20Reinterpretations/large&path=%2Fmnt%2FNAS%2Fpepestore%2FLunz%2FLunz%20Reinterpretations&metadata=false","duration":318,"trackType":"wma","samplerate":44.1,"bitdepth":"32 bit","channels":2} Jan 15 09:58:48 volumio volumio[7930]: info: CoreStateMachine::startPlaybackTimer Jan 15 09:58:48 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:48 volumio volumio[7930]: info: ControllerMpd::seek Jan 15 09:58:48 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:48 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:48 volumio volumio[7930]: error: null Jan 15 09:58:48 volumio volumio[7930]: info: Jan 15 09:58:48 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:48 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:48 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:48 volumio volumio[7930]: info: Jan 15 09:58:48 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:48 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:48 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:48 volumio volumio[7930]: info: Jan 15 09:58:48 volumio volumio[7930]: ---------------------------- MPD announces state update: player Jan 15 09:58:48 volumio volumio[7930]: info: ControllerMpd::getState Jan 15 09:58:48 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand status Jan 15 09:58:48 volumio volumio[7930]: info: sendMpdCommand status took 11 milliseconds Jan 15 09:58:48 volumio volumio[7930]: info: sendMpdCommand status took 8 milliseconds Jan 15 09:58:48 volumio volumio[7930]: info: sendMpdCommand status took 5 milliseconds Jan 15 09:58:48 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:48 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:48 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:48 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:48 volumio volumio[7930]: verbose: ControllerMpd::parseState Jan 15 09:58:48 volumio volumio[7930]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jan 15 09:58:48 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 15 09:58:48 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 15 09:58:48 volumio volumio[7930]: info: sendMpdCommand playlistinfo took 5 milliseconds Jan 15 09:58:48 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:48 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:48 volumio volumio[7930]: verbose: ControllerMpd::parseTrackInfo Jan 15 09:58:48 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:48 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:48 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":73891,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"169 Kbps","isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:48 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:48 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:48 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus play Jan 15 09:58:48 volumio volumio[7930]: info: Received an update from plugin. extracting info from payload Jan 15 09:58:48 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:48 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:48 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:48 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:48 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:48 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:48 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":73891,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"169 Kbps","isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:48 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:48 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:48 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus play Jan 15 09:58:48 volumio volumio[7930]: info: Received an update from plugin. extracting info from payload Jan 15 09:58:48 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:48 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:48 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:48 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:48 volumio volumio[7930]: info: ControllerMpd::pushState Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::servicePushState Jan 15 09:58:48 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:48 volumio volumio[7930]: verbose: STATE SERVICE {"status":"play","position":0,"seek":73891,"duration":318,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"169 Kbps","isStreaming":false,"title":"Clue (Alias remix)","artist":"Lunz","album":"Lunz Reinterpretations","uri":"NAS/pepestore/Lunz/Lunz Reinterpretations/01. Clue (Alias remix).wma","trackType":"wma"} Jan 15 09:58:48 volumio volumio[7930]: verbose: CURRENT POSITION 0 Jan 15 09:58:48 volumio volumio[7930]: info: CoreStateMachine::syncState stateService play Jan 15 09:58:48 volumio volumio[7930]: info: CoreStateMachine::syncState currentStatus play Jan 15 09:58:48 volumio volumio[7930]: info: Received an update from plugin. extracting info from payload Jan 15 09:58:48 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:48 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:48 volumio volumio[7930]: info: CoreStateMachine::pushState Jan 15 09:58:48 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::volumioPushState Jan 15 09:58:48 volumio volumio[7930]: info: ------------------------------ 82ms Jan 15 09:58:48 volumio volumio[7930]: info: ------------------------------ 80ms Jan 15 09:58:48 volumio volumio[7930]: info: ------------------------------ 78ms Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 15 09:58:48 volumio volumio[7930]: info: CoreCommandRouter::volumioGetState Jan 15 09:58:48 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:58:48 volumio volumio[7930]: info: Listing playlists Jan 15 09:58:48 volumio volumio[7930]: info: Listing playlists Jan 15 09:58:58 volumio volumio[7930]: info: CoreCommandRouter::volumioGetState Jan 15 09:58:58 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:59:08 volumio volumio[7930]: info: CoreCommandRouter::volumioGetState Jan 15 09:59:08 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:59:08 volumio volumio[7930]: info: Listing playlists Jan 15 09:59:08 volumio volumio[7930]: info: Listing playlists Jan 15 09:59:18 volumio volumio[7930]: info: CoreCommandRouter::volumioGetState Jan 15 09:59:18 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:59:25 volumio volumio[7930]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Marianne%20Faithfull/Broken%20English/14459cfc-4753-4db6-9f21-64176f726660.png' Jan 15 09:59:26 volumio volumio[7930]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Mark%20Knopfler/The%20Studio%20Albums%202009%20%E2%80%93%202018/530bab58-e6ad-4324-8e04-531cdeb03652.jpg' Jan 15 09:59:26 volumio volumio[7930]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Kings%20of%20Convenience/Riot%20on%20an%20Empty%20Street/66b8152e-e34c-46af-a2da-7a536025d541.png' Jan 15 09:59:28 volumio volumio[7930]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Jan 15 09:59:28 volumio volumio[7930]: info: CURURI: albums://Madredeus/Ainda Jan 15 09:59:28 volumio volumio[7930]: info: Preload queue cleared Jan 15 09:59:28 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Madredeus/Ainda/01. Guitarra.wma Jan 15 09:59:28 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Madredeus/Ainda/02. Milagre.wma Jan 15 09:59:28 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Madredeus/Ainda/03. Céu da Mouraria.wma Jan 15 09:59:28 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Madredeus/Ainda/04. Miradouro de Santa Catarina.wma Jan 15 09:59:28 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Madredeus/Ainda/05. A cidade e os campos.wma Jan 15 09:59:28 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Madredeus/Ainda/06. O Tejo.wma Jan 15 09:59:28 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Madredeus/Ainda/07. Viagens interditas.wma Jan 15 09:59:28 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Madredeus/Ainda/08. Alfama.wma Jan 15 09:59:28 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Madredeus/Ainda/09. Ainda.wma Jan 15 09:59:28 volumio volumio[7930]: info: Preloading song: music-library/NAS/pepestore/Madredeus/Ainda/10. Maio maduro maio.wma Jan 15 09:59:28 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Madredeus/Ainda/01. Guitarra.wma in service mpd Jan 15 09:59:28 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Madredeus/Ainda/05. A cidade e os campos.wma in service mpd Jan 15 09:59:28 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Madredeus/Ainda/02. Milagre.wma in service mpd Jan 15 09:59:28 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Madredeus/Ainda/03. Céu da Mouraria.wma in service mpd Jan 15 09:59:28 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Madredeus/Ainda/04. Miradouro de Santa Catarina.wma in service mpd Jan 15 09:59:28 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Madredeus/Ainda/large&path=%2Fmnt%2FNAS%2Fpepestore%2FMadredeus%2FAinda%2F01.%20Guitarra.wma&metadata=false Jan 15 09:59:28 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Madredeus/Ainda/01. Guitarra.wma Jan 15 09:59:28 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Madredeus/Ainda/large&path=%2Fmnt%2FNAS%2Fpepestore%2FMadredeus%2FAinda%2F05.%20A%20cidade%20e%20os%20campos.wma&metadata=false Jan 15 09:59:28 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Madredeus/Ainda/05. A cidade e os campos.wma Jan 15 09:59:28 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Madredeus/Ainda/large&path=%2Fmnt%2FNAS%2Fpepestore%2FMadredeus%2FAinda%2F02.%20Milagre.wma&metadata=false Jan 15 09:59:28 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Madredeus/Ainda/02. Milagre.wma Jan 15 09:59:28 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Madredeus/Ainda/large&path=%2Fmnt%2FNAS%2Fpepestore%2FMadredeus%2FAinda%2F03.%20C%C3%A9u%20da%20Mouraria.wma&metadata=false Jan 15 09:59:28 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Madredeus/Ainda/03. Céu da Mouraria.wma Jan 15 09:59:28 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Madredeus/Ainda/large&path=%2Fmnt%2FNAS%2Fpepestore%2FMadredeus%2FAinda%2F04.%20Miradouro%20de%20Santa%20Catarina.wma&metadata=false Jan 15 09:59:28 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Madredeus/Ainda/04. Miradouro de Santa Catarina.wma Jan 15 09:59:28 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Madredeus/Ainda/06. O Tejo.wma in service mpd Jan 15 09:59:28 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Madredeus/Ainda/07. Viagens interditas.wma in service mpd Jan 15 09:59:28 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Madredeus/Ainda/large&path=%2Fmnt%2FNAS%2Fpepestore%2FMadredeus%2FAinda%2F06.%20O%20Tejo.wma&metadata=false Jan 15 09:59:28 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Madredeus/Ainda/06. O Tejo.wma Jan 15 09:59:28 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Madredeus/Ainda/large&path=%2Fmnt%2FNAS%2Fpepestore%2FMadredeus%2FAinda%2F07.%20Viagens%20interditas.wma&metadata=false Jan 15 09:59:28 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Madredeus/Ainda/07. Viagens interditas.wma Jan 15 09:59:28 volumio volumio[7930]: info: No valid Plugin REST Endpoint Jan 15 09:59:28 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Madredeus/Ainda/08. Alfama.wma in service mpd Jan 15 09:59:28 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Madredeus/Ainda/09. Ainda.wma in service mpd Jan 15 09:59:28 volumio volumio[7930]: info: Exploding uri music-library/NAS/pepestore/Madredeus/Ainda/10. Maio maduro maio.wma in service mpd Jan 15 09:59:28 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Madredeus/Ainda/large&path=%2Fmnt%2FNAS%2Fpepestore%2FMadredeus%2FAinda%2F08.%20Alfama.wma&metadata=false Jan 15 09:59:28 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Madredeus/Ainda/08. Alfama.wma Jan 15 09:59:28 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Madredeus/Ainda/large&path=%2Fmnt%2FNAS%2Fpepestore%2FMadredeus%2FAinda%2F09.%20Ainda.wma&metadata=false Jan 15 09:59:28 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Madredeus/Ainda/09. Ainda.wma Jan 15 09:59:28 volumio volumio[7930]: info: ALBUMART /albumart?cacheid=876&web=Madredeus/Ainda/large&path=%2Fmnt%2FNAS%2Fpepestore%2FMadredeus%2FAinda%2F10.%20Maio%20maduro%20maio.wma&metadata=false Jan 15 09:59:28 volumio volumio[7930]: info: URI /mnt/NAS/pepestore/Madredeus/Ainda/10. Maio maduro maio.wma Jan 15 09:59:28 volumio volumio[7930]: info: No valid Plugin REST Endpoint Jan 15 09:59:28 volumio volumio[7930]: info: No valid Plugin REST Endpoint Jan 15 09:59:28 volumio volumio[7930]: info: CoreCommandRouter::volumioGetState Jan 15 09:59:28 volumio volumio[7930]: info: CorePlayQueue::getTrack 0 Jan 15 09:59:29 volumio volumio[7930]: info: Listing playlists Jan 15 09:59:29 volumio volumio[7930]: info: Listing playlists Jan 15 09:59:29 volumio volumio[7930]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/Men%20at%20Work/Cargo/d2726482-a850-4dbd-9906-9005e745bf7d.jpg' Jan 15 09:59:30 volumio volumio[7930]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 15 09:59:30 volumio volumio[7930]: Error: certificate is not yet valid Jan 15 09:59:30 volumio volumio[7930]: at TLSSocket.onConnectSecure (_tls_wrap.js:1497:34) Jan 15 09:59:30 volumio volumio[7930]: at TLSSocket.emit (events.js:315:20) Jan 15 09:59:30 volumio volumio[7930]: at TLSSocket._finishInit (_tls_wrap.js:932:8) Jan 15 09:59:30 volumio volumio[7930]: at TLSWrap.ssl.onhandshakedone (_tls_wrap.js:706:12) { Jan 15 09:59:30 volumio volumio[7930]: code: 'CERT_NOT_YET_VALID' Jan 15 09:59:30 volumio volumio[7930]: } Jan 15 09:59:30 volumio volumio[7930]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 15 09:59:31 volumio sudo[8275]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:59:31 volumio sudo[8275]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=1980-01-15 09:58 Jan 15 09:59:31 volumio sudo[8275]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:59:31 volumio sudo[8275]: pam_unix(sudo:session): session closed for user root Jan 15 09:59:31 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 15 09:59:31 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 15 09:59:31 volumio systemd[1]: Started dynamicswap service. Jan 15 09:59:31 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 15 09:59:31 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Jan 15 09:59:31 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 12. Jan 15 09:59:31 volumio systemd[1]: Started dynamicswap service. Jan 15 09:59:31 volumio systemd[1]: Stopped Volumio Backend Module. Jan 15 09:59:31 volumio systemd[1]: Started Volumio Backend Module. Jan 15 09:59:31 volumio systemd[1]: dynamicswap.service: Succeeded. Jan 15 09:59:33 volumio volumio[8287]: info: ------------------------------------------- Jan 15 09:59:33 volumio volumio[8287]: info: ----- Volumio3 ---- Jan 15 09:59:33 volumio volumio[8287]: info: ------------------------------------------- Jan 15 09:59:33 volumio volumio[8287]: info: ----- System startup ---- Jan 15 09:59:33 volumio volumio[8287]: info: ------------------------------------------- Jan 15 09:59:34 volumio volumio[8287]: info: MYVOLUMIO Environment detected Jan 15 09:59:34 volumio volumio[8287]: info: Plugin folders cleanup Jan 15 09:59:34 volumio volumio[8287]: info: Scanning into folder /volumio/app/plugins/ Jan 15 09:59:34 volumio volumio[8287]: info: Scanning category audio_interface Jan 15 09:59:34 volumio volumio[8287]: info: Scanning category miscellanea Jan 15 09:59:34 volumio volumio[8287]: info: Scanning category music_service Jan 15 09:59:34 volumio volumio[8287]: info: Scanning category plugins.json Jan 15 09:59:34 volumio volumio[8287]: info: Scanning category system_controller Jan 15 09:59:34 volumio volumio[8287]: info: Scanning category user_interface Jan 15 09:59:34 volumio volumio[8287]: info: Scanning into folder /data/plugins/ Jan 15 09:59:34 volumio volumio[8287]: info: Scanning category audio_interface Jan 15 09:59:34 volumio volumio[8287]: info: Scanning category music_service Jan 15 09:59:34 volumio volumio[8287]: info: Scanning category system_hardware Jan 15 09:59:34 volumio volumio[8287]: info: Plugin folders cleanup completed Jan 15 09:59:34 volumio volumio[8287]: info: ------------------------------------------- Jan 15 09:59:34 volumio volumio[8287]: info: ----- Core plugins startup ---- Jan 15 09:59:34 volumio volumio[8287]: info: ------------------------------------------- Jan 15 09:59:34 volumio volumio[8287]: info: Loading plugins from folder /volumio/app/plugins/ Jan 15 09:59:34 volumio volumio[8287]: info: Adding plugin upnp to MyMusic Plugins Jan 15 09:59:34 volumio volumio[8287]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 15 09:59:34 volumio volumio[8287]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 15 09:59:34 volumio volumio[8287]: info: Loading plugins from folder /data/plugins/ Jan 15 09:59:34 volumio volumio[8287]: info: Loading plugin "system"... Jan 15 09:59:34 volumio volumio[8287]: info: Loading plugin "appearance"... Jan 15 09:59:35 volumio volumio[8287]: info: Loading plugin "network"... Jan 15 09:59:35 volumio volumio[8287]: info: Refreshing Cached IP Addresses Jan 15 09:59:35 volumio sudo[8351]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:59:35 volumio sudo[8351]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 15 09:59:35 volumio sudo[8351]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:59:35 volumio sudo[8351]: pam_unix(sudo:session): session closed for user root Jan 15 09:59:35 volumio sudo[8353]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:59:35 volumio sudo[8353]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 15 09:59:35 volumio sudo[8353]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:59:35 volumio volumio[8287]: info: Loading plugin "services"... Jan 15 09:59:35 volumio sudo[8353]: pam_unix(sudo:session): session closed for user root Jan 15 09:59:35 volumio volumio[8287]: info: Loading plugin "alsa_controller"... Jan 15 09:59:35 volumio sudo[8361]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:59:35 volumio sudo[8361]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 15 09:59:35 volumio sudo[8361]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:59:35 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 15 09:59:35 volumio volumio[8287]: info: Loading plugin "wizard"... Jan 15 09:59:35 volumio volumio[8287]: info: Loading plugin "networkfs"... Jan 15 09:59:35 volumio volumio[8287]: info: Cannot mount NAS pepestore at system boot, trial number 1 ,retrying in 5 seconds Jan 15 09:59:35 volumio volumio[8287]: info: Starting Udev Watcher for removable devices Jan 15 09:59:35 volumio volumio[8287]: info: Ignoring mount for partition: boot Jan 15 09:59:35 volumio volumio[8287]: info: Ignoring mount for partition: volumio Jan 15 09:59:35 volumio volumio[8287]: info: Ignoring mount for partition: volumio_data Jan 15 09:59:35 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 15 09:59:35 volumio volumio[8287]: info: Loading plugin "volumio_command_line_client"... Jan 15 09:59:35 volumio volumio[8287]: info: Loading plugin "upnp"... Jan 15 09:59:35 volumio volumio[8287]: info: [316774775706] Starting Upmpd Daemon Jan 15 09:59:35 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 15 09:59:35 volumio volumio[8287]: info: Loading plugin "my_music"... Jan 15 09:59:35 volumio volumio[8287]: info: Loading plugin "mpd"... Jan 15 09:59:36 volumio volumio[8287]: info: Loading plugin "upnp_browser"... Jan 15 09:59:36 volumio volumio[8287]: info: Loading plugin "alarm-clock"... Jan 15 09:59:36 volumio sudo[8361]: pam_unix(sudo:session): session closed for user root Jan 15 09:59:36 volumio volumio[8287]: info: Plugin airplay_emulation is not enabled Jan 15 09:59:36 volumio volumio[8287]: info: Loading plugin "last_100"... Jan 15 09:59:36 volumio volumio[8287]: info: Loading plugin "webradio"... Jan 15 09:59:36 volumio volumio[8287]: info: Loading plugin "i2s_dacs"... Jan 15 09:59:36 volumio volumio[8287]: info: Loading plugin "volumiodiscovery"... Jan 15 09:59:36 volumio volumio[8287]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 15 09:59:36 volumio volumio[8287]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 15 09:59:36 volumio volumio[8287]: *** WARNING *** For more information see Jan 15 09:59:36 volumio volumio[8287]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 15 09:59:36 volumio node[8287]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 15 09:59:36 volumio volumio[8287]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 15 09:59:36 volumio volumio[8287]: *** WARNING *** For more information see Jan 15 09:59:36 volumio node[8287]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 15 09:59:36 volumio node[8287]: *** WARNING *** For more information see Jan 15 09:59:36 volumio node[8287]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 15 09:59:36 volumio node[8287]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 15 09:59:36 volumio node[8287]: *** WARNING *** For more information see Jan 15 09:59:36 volumio volumio[8287]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 15 09:59:36 volumio volumio[8287]: info: Discovery: Started advertising with name: Volumio Jan 15 09:59:36 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 15 09:59:36 volumio volumio[8287]: info: Loading plugin "ytmusic"... Jan 15 09:59:38 volumio volumio[8287]: info: Loading plugin "outputs"... Jan 15 09:59:38 volumio volumio[8287]: info: Loading plugin "albumart"... Jan 15 09:59:38 volumio volumio[8287]: info: Plugin example_plugin is not enabled Jan 15 09:59:38 volumio volumio[8287]: info: Loading plugin "inputs"... Jan 15 09:59:38 volumio volumio[8287]: info: Loading plugin "updater_comm"... Jan 15 09:59:38 volumio volumio[8287]: info: Plugin mpdemulation is not enabled Jan 15 09:59:38 volumio volumio[8287]: info: Loading plugin "rest_api"... Jan 15 09:59:38 volumio volumio[8287]: info: Loading plugin "websocket"... Jan 15 09:59:38 volumio volumio[8287]: info: Starting Socket.io Server version 2.3.0 Jan 15 09:59:38 volumio volumio[8287]: info: Plugin fusiondsp is not enabled Jan 15 09:59:38 volumio volumio[8287]: info: Plugin ir_controller is not enabled Jan 15 09:59:38 volumio volumio[8287]: info: Loading i18n strings for locale en Jan 15 09:59:38 volumio volumio[8287]: Updating browse sources language Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::initPlayerControls Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:38 volumio volumio[8287]: Forking 3 albumart workers Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 09:59:38 volumio volumio[8287]: Express server listening on port 3000 Jan 15 09:59:38 volumio volumio[8287]: [Metrics] WebUI: 5s 592.23ms Jan 15 09:59:38 volumio volumio[8287]: info: CoreStateMachine::resetVolumioState Jan 15 09:59:38 volumio volumio[8287]: info: CoreStateMachine::getcurrentVolume Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::volumioRetrievevolume Jan 15 09:59:38 volumio volumio[8287]: info: Volumio Network Manager: Network status updated: 2 Jan 15 09:59:38 volumio volumio[8287]: verbose: New Socket.io Connection to 10.0.0.31 from 10.0.0.41 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 EdgA/135.0.0.0 Engine version: 3 Transport: polling Total Clients: 1 Jan 15 09:59:38 volumio volumio[8287]: verbose: New Socket.io Connection to 10.0.0.31 from 10.0.0.41 UA: Mozilla/5.0 (Linux; Android 10; K) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 EdgA/135.0.0.0 Engine version: 3 Transport: polling Total Clients: 2 Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 09:59:38 volumio volumio[8287]: info: Reloading queue from file Jan 15 09:59:38 volumio volumio[8287]: info: VolumeController:: Volume=39 Mute =false Jan 15 09:59:38 volumio volumio[8287]: info: CoreStateMachine::pushState Jan 15 09:59:38 volumio volumio[8287]: info: CorePlayQueue::getTrack 0 Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::volumioPushState Jan 15 09:59:38 volumio volumio[8287]: info: CoreStateMachine::updateTrackBlock Jan 15 09:59:38 volumio volumio[8287]: info: CorePlayQueue::getTrackBlock Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::volumioRetrievevolume Jan 15 09:59:38 volumio volumio[8287]: info: CoreStateMachine::setRepeat true single undefined Jan 15 09:59:38 volumio volumio[8287]: info: CoreStateMachine::pushState Jan 15 09:59:38 volumio volumio[8287]: info: CorePlayQueue::getTrack 0 Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::volumioPushState Jan 15 09:59:38 volumio volumio[8287]: info: CoreStateMachine::setRandom null Jan 15 09:59:38 volumio volumio[8287]: info: CoreStateMachine::pushState Jan 15 09:59:38 volumio volumio[8287]: info: CorePlayQueue::getTrack 0 Jan 15 09:59:38 volumio volumio[8287]: info: CoreCommandRouter::volumioPushState Jan 15 09:59:38 volumio volumio[8287]: info: Setting Device type: Raspberry PI Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::volumioGetVisibleSources Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::volumioGetState Jan 15 09:59:39 volumio volumio[8287]: info: CorePlayQueue::getTrack 0 Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Jan 15 09:59:39 volumio volumio[8287]: info: Received Get System Info Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Jan 15 09:59:39 volumio volumio[8287]: info: Discovery: Getting this device information Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::volumioGetState Jan 15 09:59:39 volumio volumio[8287]: info: CorePlayQueue::getTrack 0 Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::volumioGetState Jan 15 09:59:39 volumio volumio[8287]: info: CorePlayQueue::getTrack 0 Jan 15 09:59:39 volumio volumio[8287]: info: Listing playlists Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::volumioGetQueue Jan 15 09:59:39 volumio volumio[8287]: info: CoreStateMachine::getQueue Jan 15 09:59:39 volumio volumio[8287]: info: CorePlayQueue::getQueue Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::volumioGetState Jan 15 09:59:39 volumio volumio[8287]: info: CorePlayQueue::getTrack 0 Jan 15 09:59:39 volumio volumio[8287]: info: VolumeController:: Volume=39 Mute =false Jan 15 09:59:39 volumio volumio[8287]: info: CoreStateMachine::pushState Jan 15 09:59:39 volumio volumio[8287]: info: CorePlayQueue::getTrack 0 Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::volumioPushState Jan 15 09:59:39 volumio volumio[8287]: info: Completed loading Core Plugins Jan 15 09:59:39 volumio volumio[8287]: info: Preparing to generate the ALSA configuration file Jan 15 09:59:39 volumio volumio[8287]: info: Asound.conf file unchanged, so no further update is needed Jan 15 09:59:39 volumio volumio[8287]: info: Output device has changed, restarting MPD Jan 15 09:59:39 volumio sudo[8423]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:59:39 volumio sudo[8423]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 15 09:59:39 volumio sudo[8423]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:59:39 volumio sudo[8423]: pam_unix(sudo:session): session closed for user root Jan 15 09:59:39 volumio volumio[8287]: info: ___________ START PLUGINS ___________ Jan 15 09:59:39 volumio volumio[8287]: info: ControllerMpd::onStart: Initializing MPD Jan 15 09:59:39 volumio volumio[8287]: info: Creating MPD Configuration file Jan 15 09:59:39 volumio sudo[8426]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:59:39 volumio sudo[8426]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 15 09:59:39 volumio sudo[8426]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:59:39 volumio sudo[8428]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:59:39 volumio sudo[8428]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 15 09:59:39 volumio sudo[8428]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:59:39 volumio sudo[8428]: pam_unix(sudo:session): session closed for user root Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 15 09:59:39 volumio systemd[1]: Stopping Music Player Daemon... Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 15 09:59:39 volumio volumio[8287]: info: [316774779629] CoreMusicLibrary::Adding element Media Servers Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:59:39 volumio sudo[8432]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:59:39 volumio sudo[8432]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 15 09:59:39 volumio sudo[8432]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:59:39 volumio systemd[1]: mpd.service: Succeeded. Jan 15 09:59:39 volumio systemd[1]: Stopped Music Player Daemon. Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 15 09:59:39 volumio volumio[8287]: info: [316774779738] CoreMusicLibrary::Adding element Last_100 Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 15 09:59:39 volumio volumio[8287]: info: [316774779743] CoreMusicLibrary::Adding element Webradio Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:59:39 volumio volumio[8287]: Starting albumart workers Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 15 09:59:39 volumio volumio[8287]: info: Initializing BBC Radios Jan 15 09:59:39 volumio systemd[1]: Starting Music Player Daemon... Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 15 09:59:39 volumio volumio[8287]: info: [316774779878] CoreMusicLibrary::Adding element YouTube Music Jan 15 09:59:39 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 15 09:59:39 volumio volumio[8287]: Cannot find translation for source YouTube Music Jan 15 09:59:39 volumio volumio[8287]: info: Volumio Calling Home Jan 15 09:59:39 volumio volumio[8287]: Starting albumart workers Jan 15 09:59:39 volumio volumio[8287]: Starting albumart workers Jan 15 09:59:39 volumio sudo[8434]: pam_unix(sudo:account): account root has password changed in future Jan 15 09:59:39 volumio sudo[8434]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 15 09:59:39 volumio sudo[8434]: pam_unix(sudo:session): session opened for user root by (uid=0) Jan 15 09:59:39 volumio sudo[8434]: pam_unix(sudo:session): session closed for user root Jan 15 09:59:40 volumio volumio[8287]: info: MPD Permissions set Jan 15 09:59:40 volumio volumio[8287]: info: MPD Permissions set Jan 15 09:59:40 volumio volumio[8287]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 15 09:59:40 volumio volumio[8287]: info: Volumio called home Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::volumioGetState Jan 15 09:59:40 volumio volumio[8287]: info: CorePlayQueue::getTrack 0 Jan 15 09:59:40 volumio volumio[8287]: info: Cannot mount NAS pepestore at system boot, trial number 2 ,retrying in 5 seconds Jan 15 09:59:40 volumio volumio[8287]: info: Preload queue cleared Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::volumioReplaceandPlayItems Jan 15 09:59:40 volumio volumio[8287]: info: CoreStateMachine::ClearQueue Jan 15 09:59:40 volumio volumio[8287]: info: CoreStateMachine::stop Jan 15 09:59:40 volumio volumio[8287]: info: CoreStateMachine::setConsumeUpdateService undefined Jan 15 09:59:40 volumio volumio[8287]: info: CorePlayQueue::clearPlayQueue Jan 15 09:59:40 volumio volumio[8287]: info: CorePlayQueue::saveQueue Jan 15 09:59:40 volumio volumio[8287]: info: CoreCommandRouter::volumioPushQueue Jan 15 09:59:40 volumio volumio[8287]: info: CoreStateMachine::addQueueItems Jan 15 09:59:40 volumio volumio[8287]: info: CorePlayQueue::addQueueItems Jan 15 09:59:40 volumio volumio[8287]: info: Preload queue cleared Jan 15 09:59:40 volumio volumio[8287]: info: Adding Item to queue: albums://Madredeus/Ainda Jan 15 09:59:40 volumio volumio[8287]: info: Exploding uri albums://Madredeus/Ainda in service mpd Jan 15 09:59:40 volumio volumio[8287]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 15 09:59:40 volumio volumio[8287]: TypeError: Cannot read property 'sendCommand' of undefined Jan 15 09:59:40 volumio volumio[8287]: at ControllerMpd.explodeUri (/volumio/app/plugins/music_service/mpd/index.js:2121:20) Jan 15 09:59:40 volumio volumio[8287]: at CoreCommandRouter.explodeUriFromService (/volumio/app/index.js:1384:16) Jan 15 09:59:40 volumio volumio[8287]: at CorePlayQueue.explodeUriFromCache (/volumio/app/playqueue.js:123:24) Jan 15 09:59:40 volumio volumio[8287]: at CorePlayQueue.explodeUri (/volumio/app/playqueue.js:181:19) Jan 15 09:59:40 volumio volumio[8287]: at CorePlayQueue.addQueueItems (/volumio/app/playqueue.js:223:30) Jan 15 09:59:40 volumio volumio[8287]: at CoreStateMachine.addQueueItems (/volumio/app/statemachine.js:247:25) Jan 15 09:59:40 volumio volumio[8287]: at CoreCommandRouter.replaceAndPlay (/volumio/app/index.js:526:23) Jan 15 09:59:40 volumio volumio[8287]: at CoreCommandRouter.playItemsList (/volumio/app/index.js:484:17) Jan 15 09:59:40 volumio volumio[8287]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:142:33) Jan 15 09:59:40 volumio volumio[8287]: at Socket.emit (events.js:315:20) Jan 15 09:59:40 volumio volumio[8287]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Jan 15 09:59:40 volumio volumio[8287]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Jan 15 09:59:40 volumio volumio[8287]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 15 09:59:41 volumio sudo[8491]: pam_unix(sudo:account): account volumio has password changed in future Jan 15 09:59:41 volumio sudo[8491]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=1980-01-15 09:58 Jan 15 09:59:41 volumio sudo[8491]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 06:54:47 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="436f3f84f6d0b4ffc344f0bc132a32e8"