-- Logs begin at Thu 2019-02-14 13:12:00 MSK, end at Wed 2026-08-26 10:50:11 MSK. -- Aug 26 10:49:20 volumio volumio[8053]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Aug 26 10:49:25 volumio volumio[8053]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 10:49:25 volumio volumio[8053]: Error: connect ECONNREFUSED 158.69.209.125:443 Aug 26 10:49:25 volumio volumio[8053]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Aug 26 10:49:25 volumio volumio[8053]: errno: -111, Aug 26 10:49:25 volumio volumio[8053]: code: 'ECONNREFUSED', Aug 26 10:49:25 volumio volumio[8053]: syscall: 'connect', Aug 26 10:49:25 volumio volumio[8053]: address: '158.69.209.125', Aug 26 10:49:25 volumio volumio[8053]: port: 443 Aug 26 10:49:25 volumio volumio[8053]: } Aug 26 10:49:25 volumio volumio[8053]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 10:49:26 volumio sudo[8414]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-08-26 10:48 Aug 26 10:49:26 volumio sudo[8414]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 10:49:26 volumio sudo[8414]: pam_unix(sudo:session): session closed for user root Aug 26 10:49:30 volumio volumio-remote-updater[585]: [2026-08-26 10:49:30] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Aug 26 10:49:30 volumio volumio-remote-updater[585]: [2026-08-26 10:49:30] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Aug 26 10:49:30 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Aug 26 10:49:30 volumio volumio5-onboarding[1019]: time=2026-08-26T10:49:30.704+03:00 level=ERROR msg="failed reading message" error="websocket: close 1006 (abnormal closure): unexpected EOF" Aug 26 10:49:30 volumio volumio5-onboarding[1019]: time=2026-08-26T10:49:30.716+03:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 26 10:49:30 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Aug 26 10:49:30 volumio systemd[1]: Started dynamicswap service. Aug 26 10:49:30 volumio systemd[1]: dynamicswap.service: Succeeded. Aug 26 10:49:30 volumio systemd[1]: volumio.service: Service RestartSec=100ms expired, scheduling restart. Aug 26 10:49:30 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2. Aug 26 10:49:30 volumio systemd[1]: Stopped Volumio Backend Module. Aug 26 10:49:30 volumio systemd[1]: Started Volumio Backend Module. Aug 26 10:49:30 volumio systemd[1]: Started dynamicswap service. Aug 26 10:49:30 volumio systemd[1]: dynamicswap.service: Succeeded. Aug 26 10:49:31 volumio volumio5-onboarding[1019]: time=2026-08-26T10:49:31.718+03:00 level=WARN msg="reconnection attempt failed" error="dial tcp 127.0.0.1:3000: connect: connection refused" Aug 26 10:49:32 volumio volumio[8439]: info: ------------------------------------------- Aug 26 10:49:32 volumio volumio[8439]: info: ----- Volumio3 ---- Aug 26 10:49:32 volumio volumio[8439]: info: ------------------------------------------- Aug 26 10:49:32 volumio volumio[8439]: info: ----- System startup ---- Aug 26 10:49:32 volumio volumio[8439]: info: ------------------------------------------- Aug 26 10:49:33 volumio volumio[8439]: info: MYVOLUMIO Environment detected Aug 26 10:49:33 volumio volumio[8439]: info: Plugin folders cleanup Aug 26 10:49:33 volumio volumio[8439]: info: Scanning into folder /volumio/app/plugins/ Aug 26 10:49:33 volumio volumio[8439]: info: Scanning category audio_interface Aug 26 10:49:33 volumio volumio[8439]: info: Scanning category miscellanea Aug 26 10:49:33 volumio volumio[8439]: info: Scanning category music_service Aug 26 10:49:33 volumio volumio[8439]: info: Scanning category plugins.json Aug 26 10:49:33 volumio volumio[8439]: info: Scanning category system_controller Aug 26 10:49:33 volumio volumio[8439]: info: Scanning category user_interface Aug 26 10:49:33 volumio volumio[8439]: info: Scanning into folder /data/plugins/ Aug 26 10:49:33 volumio volumio[8439]: info: Plugin folders cleanup completed Aug 26 10:49:33 volumio volumio[8439]: info: ------------------------------------------- Aug 26 10:49:33 volumio volumio[8439]: info: ----- Core plugins startup ---- Aug 26 10:49:33 volumio volumio[8439]: info: ------------------------------------------- Aug 26 10:49:33 volumio volumio[8439]: info: Loading plugins from folder /volumio/app/plugins/ Aug 26 10:49:33 volumio volumio[8439]: info: Adding plugin upnp to MyMusic Plugins Aug 26 10:49:33 volumio volumio[8439]: info: Adding plugin airplay_emulation to MyMusic Plugins Aug 26 10:49:33 volumio volumio[8439]: info: Adding plugin upnp_browser to MyMusic Plugins Aug 26 10:49:33 volumio volumio[8439]: info: Loading plugins from folder /data/plugins/ Aug 26 10:49:33 volumio volumio[8439]: info: Loading plugin "system"... Aug 26 10:49:33 volumio volumio[8439]: info: Loading plugin "appearance"... Aug 26 10:49:34 volumio volumio[8439]: info: Loading plugin "network"... Aug 26 10:49:34 volumio volumio[8439]: info: Refreshing Cached IP Addresses Aug 26 10:49:34 volumio sudo[8466]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 10:49:34 volumio sudo[8466]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 10:49:34 volumio sudo[8466]: pam_unix(sudo:session): session closed for user root Aug 26 10:49:34 volumio volumio[8439]: info: Loading plugin "services"... Aug 26 10:49:34 volumio sudo[8468]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 10:49:34 volumio sudo[8468]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 10:49:34 volumio volumio[8439]: info: Loading plugin "volumio5onboarding"... Aug 26 10:49:34 volumio sudo[8468]: pam_unix(sudo:session): session closed for user root Aug 26 10:49:34 volumio volumio[8439]: info: Loading plugin "alsa_controller"... Aug 26 10:49:34 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 10:49:34 volumio volumio[8439]: info: Loading plugin "wizard"... Aug 26 10:49:34 volumio volumio[8439]: info: Loading plugin "networkfs"... Aug 26 10:49:34 volumio volumio[8439]: info: Starting Udev Watcher for removable devices Aug 26 10:49:34 volumio volumio[8439]: info: Ignoring mount for partition: boot Aug 26 10:49:34 volumio volumio[8439]: info: Ignoring mount for partition: volumio Aug 26 10:49:34 volumio volumio[8439]: info: Ignoring mount for partition: volumio_data Aug 26 10:49:34 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 26 10:49:34 volumio volumio[8439]: info: Loading plugin "volumio_command_line_client"... Aug 26 10:49:34 volumio volumio[8439]: info: Loading plugin "upnp"... Aug 26 10:49:34 volumio volumio[8439]: info: [1787730574672] Starting Upmpd Daemon Aug 26 10:49:34 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 26 10:49:34 volumio volumio[8439]: info: Loading plugin "my_music"... Aug 26 10:49:34 volumio volumio[8439]: info: Loading plugin "mpd"... Aug 26 10:49:35 volumio volumio[8439]: info: Loading plugin "upnp_browser"... Aug 26 10:49:35 volumio volumio[8439]: info: Starting UPNP Browser Aug 26 10:49:35 volumio volumio[8439]: info: Loading plugin "alarm-clock"... Aug 26 10:49:35 volumio volumio[8439]: info: Loading plugin "airplay_emulation"... Aug 26 10:49:35 volumio volumio[8439]: info: Starting Shairport Sync Aug 26 10:49:35 volumio volumio[8439]: info: Loading plugin "last_100"... Aug 26 10:49:35 volumio volumio[8439]: info: Loading plugin "webradio"... Aug 26 10:49:35 volumio volumio[8439]: info: Loading plugin "i2s_dacs"... Aug 26 10:49:35 volumio volumio[8439]: info: I2S DAC not set, start Auto-detection Aug 26 10:49:35 volumio volumio[8439]: info: Loading plugin "volumiodiscovery"... Aug 26 10:49:35 volumio volumio[8439]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 26 10:49:35 volumio volumio[8439]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 10:49:35 volumio volumio[8439]: *** WARNING *** For more information see Aug 26 10:49:35 volumio node[8439]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Aug 26 10:49:35 volumio volumio[8439]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 26 10:49:35 volumio volumio[8439]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 10:49:35 volumio volumio[8439]: *** WARNING *** For more information see Aug 26 10:49:35 volumio node[8439]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 10:49:35 volumio node[8439]: *** WARNING *** For more information see Aug 26 10:49:35 volumio node[8439]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Aug 26 10:49:35 volumio node[8439]: *** WARNING *** Please fix your application to use the native API of Avahi! Aug 26 10:49:35 volumio node[8439]: *** WARNING *** For more information see Aug 26 10:49:35 volumio volumio[8439]: info: Applying required configuration parameters for plugin volumiodiscovery Aug 26 10:49:35 volumio volumio[8439]: info: Discovery: Started advertising with name: Volumio Aug 26 10:49:35 volumio volumio-remote-updater[585]: [2026-08-26 10:49:35] [connect] Successful connection Aug 26 10:49:35 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Aug 26 10:49:35 volumio volumio[8439]: info: Loading plugin "outputs"... Aug 26 10:49:35 volumio volumio[8439]: info: Loading plugin "albumart"... Aug 26 10:49:35 volumio volumio[8439]: info: Plugin example_plugin is not enabled Aug 26 10:49:35 volumio volumio[8439]: info: Loading plugin "inputs"... Aug 26 10:49:35 volumio volumio[8439]: info: Loading plugin "updater_comm"... Aug 26 10:49:36 volumio volumio[8439]: info: Plugin mpdemulation is not enabled Aug 26 10:49:36 volumio volumio[8439]: info: Loading plugin "rest_api"... Aug 26 10:49:36 volumio volumio[8439]: info: Loading plugin "websocket"... Aug 26 10:49:36 volumio volumio[8439]: info: Starting Socket.io Server version 2.3.0 Aug 26 10:49:36 volumio volumio[8439]: info: Loading i18n strings for locale ru Aug 26 10:49:36 volumio volumio[8439]: Updating browse sources language Aug 26 10:49:36 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 10:49:36 volumio volumio[8439]: Forking 3 albumart workers Aug 26 10:49:36 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 26 10:49:36 volumio volumio[8439]: info: CoreCommandRouter::initPlayerControls Aug 26 10:49:36 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:36 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:36 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:36 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:36 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:36 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:36 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:36 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:36 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 26 10:49:36 volumio volumio[8439]: Express server listening on port 3000 Aug 26 10:49:36 volumio volumio[8439]: [Metrics] WebUI: 4s 416.31ms Aug 26 10:49:36 volumio volumio[8439]: info: CoreStateMachine::resetVolumioState Aug 26 10:49:36 volumio volumio[8439]: info: CoreStateMachine::getcurrentVolume Aug 26 10:49:36 volumio volumio[8439]: info: CoreCommandRouter::volumioRetrievevolume Aug 26 10:49:36 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 10:49:36 volumio volumio[8439]: info: Volumio Network Manager: Network status updated: 1 Aug 26 10:49:36 volumio volumio[8439]: verbose: New Socket.io Connection to 192.168.128.142 from 192.168.128.150 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:154.0) Gecko/20100101 Firefox/154.0 Engine version: 3 Transport: polling Total Clients: 1 Aug 26 10:49:36 volumio volumio[8439]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 2 Aug 26 10:49:36 volumio volumio-remote-updater[585]: [2026-08-26 10:49:36] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1787730575 101 Aug 26 10:49:36 volumio volumio[8439]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 2 Aug 26 10:49:37 volumio volumio[8439]: info: Reloading queue from file Aug 26 10:49:37 volumio volumio[8439]: verbose: New Socket.io Connection to 192.168.128.142 from 192.168.128.150 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:154.0) Gecko/20100101 Firefox/154.0 Engine version: 3 Transport: polling Total Clients: 3 Aug 26 10:49:37 volumio volumio[8439]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Aug 26 10:49:37 volumio volumio[8439]: info: VolumeController:: Volume=40 Mute =false Aug 26 10:49:37 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:37 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:37 volumio volumio[8439]: info: CoreStateMachine::updateTrackBlock Aug 26 10:49:37 volumio volumio[8439]: info: CorePlayQueue::getTrackBlock Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::volumioRetrievevolume Aug 26 10:49:37 volumio volumio[8439]: Starting albumart workers Aug 26 10:49:37 volumio volumio[8439]: info: Setting Device type: Raspberry PI Aug 26 10:49:37 volumio volumio[8439]: info: CoreStateMachine::setRepeat null single undefined Aug 26 10:49:37 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:37 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:37 volumio volumio[8439]: info: CoreStateMachine::setRandom null Aug 26 10:49:37 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:37 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:37 volumio volumio[8439]: Starting albumart workers Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 26 10:49:37 volumio volumio[8439]: Starting albumart workers Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::volumioGetVisibleSources Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::volumioGetState Aug 26 10:49:37 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::volumioGetState Aug 26 10:49:37 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 26 10:49:37 volumio volumio[8439]: info: Received Get System Info Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 26 10:49:37 volumio volumio[8439]: info: Discovery: Getting this device information Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::volumioGetState Aug 26 10:49:37 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::volumioGetState Aug 26 10:49:37 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:37 volumio volumio[8439]: info: Listing playlists Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::volumioGetQueue Aug 26 10:49:37 volumio volumio[8439]: info: CoreStateMachine::getQueue Aug 26 10:49:37 volumio volumio[8439]: info: CorePlayQueue::getQueue Aug 26 10:49:37 volumio volumio[8439]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Aug 26 10:49:37 volumio volumio[8439]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Aug 26 10:49:37 volumio volumio[8439]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: Go-http-client/1.1 Engine version: 3 Transport: websocket Total Clients: 4 Aug 26 10:49:37 volumio volumio[8439]: info: VolumeController:: Volume=40 Mute =false Aug 26 10:49:37 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:37 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:37 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:37 volumio volumio[8439]: info: Completed loading Core Plugins Aug 26 10:49:37 volumio volumio[8439]: info: Preparing to generate the ALSA configuration file Aug 26 10:49:38 volumio volumio[8439]: info: Asound.conf file unchanged, so no further update is needed Aug 26 10:49:38 volumio volumio[8439]: info: Output device has changed, restarting MPD Aug 26 10:49:38 volumio volumio[8439]: info: Output device has changed, restarting Shairport Sync Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 10:49:38 volumio sudo[8541]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 26 10:49:38 volumio sudo[8541]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 10:49:38 volumio sudo[8543]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 26 10:49:38 volumio sudo[8543]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 10:49:38 volumio sudo[8541]: pam_unix(sudo:session): session closed for user root Aug 26 10:49:38 volumio systemd[1]: Stopping Music Player Daemon... Aug 26 10:49:38 volumio systemd[1]: mpd.service: Succeeded. Aug 26 10:49:38 volumio systemd[1]: Stopped Music Player Daemon. Aug 26 10:49:38 volumio volumio[8439]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 10:49:38 volumio volumio[8439]: info: ___________ START PLUGINS ___________ Aug 26 10:49:38 volumio systemd[1]: Starting Music Player Daemon... Aug 26 10:49:38 volumio volumio[8439]: info: ControllerMpd::onStart: Initializing MPD Aug 26 10:49:38 volumio volumio[8439]: info: Creating MPD Configuration file Aug 26 10:49:38 volumio sudo[8563]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumio5-onboarding.service Aug 26 10:49:38 volumio sudo[8563]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 10:49:38 volumio sudo[8569]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Aug 26 10:49:38 volumio sudo[8569]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 10:49:38 volumio sudo[8569]: pam_unix(sudo:session): session closed for user root Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 10:49:38 volumio volumio[8439]: info: [1787730578354] CoreMusicLibrary::Adding element Медиа-серверы Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 10:49:38 volumio sudo[8563]: pam_unix(sudo:session): session closed for user root Aug 26 10:49:38 volumio sudo[8573]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Aug 26 10:49:38 volumio sudo[8573]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 10:49:38 volumio volumio[8439]: info: UPNP Browser: Client initialized successfully Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 10:49:38 volumio systemd[1]: mpd.service: Control process exited, code=killed, status=15/TERM Aug 26 10:49:38 volumio systemd[1]: mpd.service: Succeeded. Aug 26 10:49:38 volumio systemd[1]: Stopped Music Player Daemon. Aug 26 10:49:38 volumio volumio[8439]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 10:49:38 volumio volumio[8439]: info: [1787730578516] CoreMusicLibrary::Adding element Last_100 Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 10:49:38 volumio systemd[1]: Starting Music Player Daemon... Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Aug 26 10:49:38 volumio volumio[8439]: info: [1787730578522] CoreMusicLibrary::Adding element Webradio Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 10:49:38 volumio volumio[8439]: info: Initializing BBC Radios Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: Volumio Calling Home Aug 26 10:49:38 volumio sudo[8578]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Aug 26 10:49:38 volumio sudo[8578]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 10:49:38 volumio sudo[8578]: pam_unix(sudo:session): session closed for user root Aug 26 10:49:38 volumio volumio[8439]: info: MPD Permissions set Aug 26 10:49:38 volumio volumio[8439]: info: MPD Permissions set Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:49:38 volumio volumio[8439]: info: Starting Shairport Sync Aug 26 10:49:38 volumio volumio[8439]: info: Starting Shairport Sync Aug 26 10:49:39 volumio sudo[8606]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 10:49:39 volumio volumio[8439]: info: Starting Shairport Sync Aug 26 10:49:39 volumio sudo[8606]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 10:49:39 volumio sudo[8608]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 10:49:39 volumio sudo[8608]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 10:49:39 volumio sudo[8611]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Aug 26 10:49:39 volumio sudo[8611]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 10:49:39 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 26 10:49:39 volumio systemd[1]: shairport-sync.service: Succeeded. Aug 26 10:49:39 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 26 10:49:39 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 26 10:49:39 volumio sudo[8606]: pam_unix(sudo:session): session closed for user root Aug 26 10:49:39 volumio sudo[8608]: pam_unix(sudo:session): session closed for user root Aug 26 10:49:39 volumio volumio[8439]: info: Shairport-Sync Started Aug 26 10:49:39 volumio volumio[8439]: Error adding Membership: Error: addMembership EINVAL Aug 26 10:49:39 volumio volumio[8439]: info: Shairport-Sync Started Aug 26 10:49:39 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Aug 26 10:49:39 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Aug 26 10:49:39 volumio systemd[1]: shairport-sync.service: Succeeded. Aug 26 10:49:39 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Aug 26 10:49:39 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Aug 26 10:49:39 volumio sudo[8611]: pam_unix(sudo:session): session closed for user root Aug 26 10:49:39 volumio volumio[8439]: info: Shairport-Sync Started Aug 26 10:49:40 volumio mpd[8595]: Aug 26 10:49 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Aug 26 10:49:40 volumio systemd[1]: Started Music Player Daemon. Aug 26 10:49:40 volumio sudo[8573]: pam_unix(sudo:session): session closed for user root Aug 26 10:49:40 volumio sudo[8543]: pam_unix(sudo:session): session closed for user root Aug 26 10:49:40 volumio volumio[8439]: info: Completed starting Core Plugins Aug 26 10:49:40 volumio volumio[8439]: info: ------------------------------------------- Aug 26 10:49:40 volumio volumio[8439]: info: ----- MyVolumio plugins startup ---- Aug 26 10:49:40 volumio volumio[8439]: info: ------------------------------------------- Aug 26 10:49:40 volumio volumio[8439]: info: [MyVolumio PluginManager] Fetching plans data.... Aug 26 10:49:40 volumio volumio[8439]: error: MPD error: The expression evaluated to a falsy value: Aug 26 10:49:40 volumio volumio[8439]: assert.ok(self.idling) Aug 26 10:49:40 volumio volumio[8439]: error: The expression evaluated to a falsy value: Aug 26 10:49:40 volumio volumio[8439]: assert.ok(self.idling) Aug 26 10:49:40 volumio volumio[8439]: info: MPD running with PID8595 Aug 26 10:49:40 volumio volumio[8439]: ,establishing connection Aug 26 10:49:40 volumio volumio[8439]: error: MPD error: The expression evaluated to a falsy value: Aug 26 10:49:40 volumio volumio[8439]: assert.ok(self.idling) Aug 26 10:49:40 volumio volumio[8439]: error: The expression evaluated to a falsy value: Aug 26 10:49:40 volumio volumio[8439]: assert.ok(self.idling) Aug 26 10:49:40 volumio volumio[8439]: error: updateQueue error: null Aug 26 10:49:44 volumio sudo[8696]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 26 10:49:44 volumio sudo[8696]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 10:49:44 volumio sudo[8696]: pam_unix(sudo:session): session closed for user root Aug 26 10:49:44 volumio sudo[8698]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 26 10:49:44 volumio sudo[8698]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 10:49:44 volumio sudo[8698]: pam_unix(sudo:session): session closed for user root Aug 26 10:49:44 volumio sudo[8702]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Aug 26 10:49:44 volumio sudo[8702]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 26 10:49:44 volumio sudo[8702]: pam_unix(sudo:session): session closed for user root Aug 26 10:49:44 volumio volumio[8439]: info: Upmpdcli Daemon Started Aug 26 10:49:45 volumio volumio[8439]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Aug 26 10:49:47 volumio volumio[8439]: info: Volumio called home Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::volumioPlay Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::play index undefined Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::startPlaybackTimer Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/Fonovaya/01_Hubert_Giraud-Sous_le_ciel_de_Paris.mp3 Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand stop Aug 26 10:49:48 volumio volumio[8439]: info: sendMpdCommand stop took 3 milliseconds Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand clear Aug 26 10:49:48 volumio volumio[8439]: info: Aug 26 10:49:48 volumio volumio[8439]: ---------------------------- MPD announces system playlist update Aug 26 10:49:48 volumio volumio[8439]: info: Ignoring MPD Status Update Aug 26 10:49:48 volumio volumio[8439]: info: sendMpdCommand clear took 4 milliseconds Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/Fonovaya/01_Hubert_Giraud-Sous_le_ciel_de_Paris.mp3" Aug 26 10:49:48 volumio volumio[8439]: info: Aug 26 10:49:48 volumio volumio[8439]: ---------------------------- MPD announces system playlist update Aug 26 10:49:48 volumio volumio[8439]: info: Ignoring MPD Status Update Aug 26 10:49:48 volumio volumio[8439]: info: Aug 26 10:49:48 volumio volumio[8439]: ---------------------------- MPD announces system playlist update Aug 26 10:49:48 volumio volumio[8439]: info: Ignoring MPD Status Update Aug 26 10:49:48 volumio volumio[8439]: error: updateQueue error: null Aug 26 10:49:48 volumio volumio[8439]: info: Aug 26 10:49:48 volumio volumio[8439]: ---------------------------- MPD announces system playlist update Aug 26 10:49:48 volumio volumio[8439]: info: Ignoring MPD Status Update Aug 26 10:49:48 volumio volumio[8439]: info: ------------------------------ 13ms Aug 26 10:49:48 volumio volumio[8439]: info: sendMpdCommand add "INTERNAL/Fonovaya/01_Hubert_Giraud-Sous_le_ciel_de_Paris.mp3" took 9 milliseconds Aug 26 10:49:48 volumio volumio[8439]: info: ------------------------------ 9ms Aug 26 10:49:48 volumio volumio[8439]: info: ------------------------------ 7ms Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand play Aug 26 10:49:48 volumio volumio[8439]: info: Aug 26 10:49:48 volumio volumio[8439]: ---------------------------- MPD announces system playlist update Aug 26 10:49:48 volumio volumio[8439]: info: Ignoring MPD Status Update Aug 26 10:49:48 volumio volumio[8439]: info: Aug 26 10:49:48 volumio volumio[8439]: ---------------------------- MPD announces system playlist update Aug 26 10:49:48 volumio volumio[8439]: info: Ignoring MPD Status Update Aug 26 10:49:48 volumio volumio[8439]: info: Aug 26 10:49:48 volumio volumio[8439]: ---------------------------- MPD announces state update: player Aug 26 10:49:48 volumio volumio[8439]: info: ------------------------------ 15ms Aug 26 10:49:48 volumio volumio[8439]: info: sendMpdCommand play took 9 milliseconds Aug 26 10:49:48 volumio volumio[8439]: info: ControllerMpd::getState Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand status Aug 26 10:49:48 volumio volumio[8439]: info: ------------------------------ 11ms Aug 26 10:49:48 volumio volumio[8439]: info: ------------------------------ 8ms Aug 26 10:49:48 volumio volumio[8439]: info: Aug 26 10:49:48 volumio volumio[8439]: ---------------------------- MPD announces state update: player Aug 26 10:49:48 volumio volumio[8439]: info: ControllerMpd::getState Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand status Aug 26 10:49:48 volumio volumio[8439]: info: Aug 26 10:49:48 volumio volumio[8439]: ---------------------------- MPD announces state update: player Aug 26 10:49:48 volumio volumio[8439]: info: ControllerMpd::getState Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand status Aug 26 10:49:48 volumio volumio[8439]: info: Aug 26 10:49:48 volumio volumio[8439]: ---------------------------- MPD announces state update: player Aug 26 10:49:48 volumio volumio[8439]: info: sendMpdCommand status took 15 milliseconds Aug 26 10:49:48 volumio volumio[8439]: info: ControllerMpd::getState Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand status Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::parseState Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 10:49:48 volumio volumio[8439]: info: Aug 26 10:49:48 volumio volumio[8439]: ---------------------------- MPD announces state update: player Aug 26 10:49:48 volumio volumio[8439]: info: ControllerMpd::getState Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand status Aug 26 10:49:48 volumio volumio[8439]: info: sendMpdCommand status took 26 milliseconds Aug 26 10:49:48 volumio volumio[8439]: info: sendMpdCommand status took 24 milliseconds Aug 26 10:49:48 volumio volumio[8439]: info: sendMpdCommand status took 12 milliseconds Aug 26 10:49:48 volumio volumio[8439]: info: sendMpdCommand playlistinfo took 10 milliseconds Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::parseState Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::parseState Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::parseState Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::parseTrackInfo Aug 26 10:49:48 volumio volumio[8439]: info: ControllerMpd::pushState Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::servicePushState Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":122,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Sous le ciel de Paris","artist":"Hubert Giraud","album":null,"uri":"INTERNAL/Fonovaya/01_Hubert_Giraud-Sous_le_ciel_de_Paris.mp3","trackType":"mp3"} Aug 26 10:49:48 volumio volumio[8439]: verbose: CURRENT POSITION 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::syncState stateService play Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::syncState currentStatus stop Aug 26 10:49:48 volumio volumio[8439]: info: ------------------------------ 58ms Aug 26 10:49:48 volumio volumio[8439]: info: Aug 26 10:49:48 volumio volumio[8439]: ---------------------------- MPD announces state update: player Aug 26 10:49:48 volumio volumio[8439]: info: ControllerMpd::getState Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand status Aug 26 10:49:48 volumio volumio[8439]: info: sendMpdCommand status took 29 milliseconds Aug 26 10:49:48 volumio volumio[8439]: info: sendMpdCommand playlistinfo took 21 milliseconds Aug 26 10:49:48 volumio volumio[8439]: info: sendMpdCommand playlistinfo took 20 milliseconds Aug 26 10:49:48 volumio volumio[8439]: info: sendMpdCommand playlistinfo took 18 milliseconds Aug 26 10:49:48 volumio volumio[8439]: info: sendMpdCommand status took 4 milliseconds Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::parseState Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::parseTrackInfo Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::parseTrackInfo Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::parseTrackInfo Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::parseState Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 10:49:48 volumio volumio[8439]: info: ControllerMpd::pushState Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::servicePushState Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: verbose: STATE SERVICE {"status":"play","position":0,"seek":114,"duration":122,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Sous le ciel de Paris","artist":"Hubert Giraud","album":null,"uri":"INTERNAL/Fonovaya/01_Hubert_Giraud-Sous_le_ciel_de_Paris.mp3","trackType":"mp3"} Aug 26 10:49:48 volumio volumio[8439]: verbose: CURRENT POSITION 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::syncState stateService play Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::syncState currentStatus play Aug 26 10:49:48 volumio volumio[8439]: info: Received an update from plugin. extracting info from payload Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:48 volumio volumio[8439]: info: ControllerMpd::pushState Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::servicePushState Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: verbose: STATE SERVICE {"status":"play","position":0,"seek":137,"duration":122,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Sous le ciel de Paris","artist":"Hubert Giraud","album":null,"uri":"INTERNAL/Fonovaya/01_Hubert_Giraud-Sous_le_ciel_de_Paris.mp3","trackType":"mp3"} Aug 26 10:49:48 volumio volumio[8439]: verbose: CURRENT POSITION 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::syncState stateService play Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::syncState currentStatus play Aug 26 10:49:48 volumio volumio[8439]: info: Received an update from plugin. extracting info from payload Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:48 volumio volumio[8439]: info: ControllerMpd::pushState Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::servicePushState Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: verbose: STATE SERVICE {"status":"play","position":0,"seek":982,"duration":122,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Sous le ciel de Paris","artist":"Hubert Giraud","album":null,"uri":"INTERNAL/Fonovaya/01_Hubert_Giraud-Sous_le_ciel_de_Paris.mp3","trackType":"mp3"} Aug 26 10:49:48 volumio volumio[8439]: verbose: CURRENT POSITION 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::syncState stateService play Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::syncState currentStatus play Aug 26 10:49:48 volumio volumio[8439]: info: Received an update from plugin. extracting info from payload Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:48 volumio volumio[8439]: info: ------------------------------ 124ms Aug 26 10:49:48 volumio volumio[8439]: info: ------------------------------ 123ms Aug 26 10:49:48 volumio volumio[8439]: info: ------------------------------ 121ms Aug 26 10:49:48 volumio volumio[8439]: info: sendMpdCommand playlistinfo took 78 milliseconds Aug 26 10:49:48 volumio volumio[8439]: info: sendMpdCommand playlistinfo took 75 milliseconds Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::parseTrackInfo Aug 26 10:49:48 volumio volumio[8439]: verbose: ControllerMpd::parseTrackInfo Aug 26 10:49:48 volumio volumio[8439]: info: ControllerMpd::pushState Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::servicePushState Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: verbose: STATE SERVICE {"status":"play","position":0,"seek":982,"duration":122,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Sous le ciel de Paris","artist":"Hubert Giraud","album":null,"uri":"INTERNAL/Fonovaya/01_Hubert_Giraud-Sous_le_ciel_de_Paris.mp3","trackType":"mp3"} Aug 26 10:49:48 volumio volumio[8439]: verbose: CURRENT POSITION 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::syncState stateService play Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::syncState currentStatus play Aug 26 10:49:48 volumio volumio[8439]: info: Received an update from plugin. extracting info from payload Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:48 volumio volumio[8439]: info: ControllerMpd::pushState Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::servicePushState Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: verbose: STATE SERVICE {"status":"play","position":0,"seek":982,"duration":122,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Sous le ciel de Paris","artist":"Hubert Giraud","album":null,"uri":"INTERNAL/Fonovaya/01_Hubert_Giraud-Sous_le_ciel_de_Paris.mp3","trackType":"mp3"} Aug 26 10:49:48 volumio volumio[8439]: verbose: CURRENT POSITION 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::syncState stateService play Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::syncState currentStatus play Aug 26 10:49:48 volumio volumio[8439]: info: Received an update from plugin. extracting info from payload Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:48 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:48 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:48 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:48 volumio volumio[8439]: info: ------------------------------ 146ms Aug 26 10:49:48 volumio volumio[8439]: info: ------------------------------ 123ms Aug 26 10:49:51 volumio volumio[8439]: info: CoreCommandRouter::volumioPlay Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::play index 6 Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::stop Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::stPlaybackTimer Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::updateTrackBlock Aug 26 10:49:51 volumio volumio[8439]: info: CorePlayQueue::getTrackBlock Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:51 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:51 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 10:49:51 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::serviceStop Aug 26 10:49:51 volumio volumio[8439]: info: CorePlayQueue::getTrack 0 Aug 26 10:49:51 volumio volumio[8439]: info: CoreCommandRouter::serviceStop Aug 26 10:49:51 volumio volumio[8439]: info: ControllerMpd::stop Aug 26 10:49:51 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand stop Aug 26 10:49:51 volumio volumio[8439]: info: sendMpdCommand stop took 6 milliseconds Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::play index undefined Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 26 10:49:51 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::startPlaybackTimer Aug 26 10:49:51 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:51 volumio volumio[8439]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/Fonovaya/04_Keiko_Matsui-Akendoras_Clock.mp3 Aug 26 10:49:51 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand stop Aug 26 10:49:51 volumio volumio[8439]: info: Aug 26 10:49:51 volumio volumio[8439]: ---------------------------- MPD announces state update: player Aug 26 10:49:51 volumio volumio[8439]: info: ControllerMpd::getState Aug 26 10:49:51 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand status Aug 26 10:49:51 volumio volumio[8439]: info: sendMpdCommand stop took 3 milliseconds Aug 26 10:49:51 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand clear Aug 26 10:49:51 volumio volumio[8439]: info: Aug 26 10:49:51 volumio volumio[8439]: ---------------------------- MPD announces state update: player Aug 26 10:49:51 volumio volumio[8439]: info: ControllerMpd::getState Aug 26 10:49:51 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand status Aug 26 10:49:51 volumio volumio[8439]: info: Aug 26 10:49:51 volumio volumio[8439]: ---------------------------- MPD announces state update: player Aug 26 10:49:51 volumio volumio[8439]: info: ControllerMpd::getState Aug 26 10:49:51 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand status Aug 26 10:49:51 volumio volumio[8439]: info: Aug 26 10:49:51 volumio volumio[8439]: ---------------------------- MPD announces system playlist update Aug 26 10:49:51 volumio volumio[8439]: info: Ignoring MPD Status Update Aug 26 10:49:51 volumio volumio[8439]: info: sendMpdCommand status took 7 milliseconds Aug 26 10:49:51 volumio volumio[8439]: info: sendMpdCommand clear took 6 milliseconds Aug 26 10:49:51 volumio volumio[8439]: info: sendMpdCommand status took 5 milliseconds Aug 26 10:49:51 volumio volumio[8439]: info: sendMpdCommand status took 3 milliseconds Aug 26 10:49:51 volumio volumio[8439]: verbose: ControllerMpd::parseState Aug 26 10:49:51 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 10:49:51 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/Fonovaya/04_Keiko_Matsui-Akendoras_Clock.mp3" Aug 26 10:49:51 volumio volumio[8439]: verbose: ControllerMpd::parseState Aug 26 10:49:51 volumio volumio[8439]: verbose: ControllerMpd::parseState Aug 26 10:49:51 volumio volumio[8439]: info: ControllerMpd::pushState Aug 26 10:49:51 volumio volumio[8439]: info: CoreCommandRouter::servicePushState Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:51 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:51 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 10:49:51 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:51 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:51 volumio volumio[8439]: 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} Aug 26 10:49:51 volumio volumio[8439]: verbose: CURRENT POSITION 6 Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::syncState stateService stop Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::syncState currentStatus stop Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:51 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:51 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:51 volumio volumio[8439]: info: No code Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:51 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:51 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:51 volumio volumio[8439]: info: ControllerMpd::pushState Aug 26 10:49:51 volumio volumio[8439]: info: CoreCommandRouter::servicePushState Aug 26 10:49:51 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:51 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: 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} Aug 26 10:49:52 volumio volumio[8439]: verbose: CURRENT POSITION 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::syncState stateService stop Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::syncState currentStatus stop Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:52 volumio volumio[8439]: info: No code Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:52 volumio volumio[8439]: info: ------------------------------ 60ms Aug 26 10:49:52 volumio volumio[8439]: info: ------------------------------ 61ms Aug 26 10:49:52 volumio volumio[8439]: info: Aug 26 10:49:52 volumio volumio[8439]: ---------------------------- MPD announces system playlist update Aug 26 10:49:52 volumio volumio[8439]: info: Ignoring MPD Status Update Aug 26 10:49:52 volumio volumio[8439]: info: Aug 26 10:49:52 volumio volumio[8439]: ---------------------------- MPD announces system playlist update Aug 26 10:49:52 volumio volumio[8439]: info: Ignoring MPD Status Update Aug 26 10:49:52 volumio volumio[8439]: error: updateQueue error: null Aug 26 10:49:52 volumio volumio[8439]: info: Aug 26 10:49:52 volumio volumio[8439]: ---------------------------- MPD announces system playlist update Aug 26 10:49:52 volumio volumio[8439]: info: Ignoring MPD Status Update Aug 26 10:49:52 volumio volumio[8439]: info: ------------------------------ 67ms Aug 26 10:49:52 volumio volumio[8439]: info: sendMpdCommand playlistinfo took 64 milliseconds Aug 26 10:49:52 volumio volumio[8439]: info: sendMpdCommand add "INTERNAL/Fonovaya/04_Keiko_Matsui-Akendoras_Clock.mp3" took 63 milliseconds Aug 26 10:49:52 volumio volumio[8439]: info: ------------------------------ 7ms Aug 26 10:49:52 volumio volumio[8439]: info: ------------------------------ 5ms Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::parseTrackInfo Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand play Aug 26 10:49:52 volumio volumio[8439]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Aug 26 10:49:52 volumio volumio[8439]: info: ------------------------------ 78ms Aug 26 10:49:52 volumio volumio[8439]: info: Aug 26 10:49:52 volumio volumio[8439]: ---------------------------- MPD announces system playlist update Aug 26 10:49:52 volumio volumio[8439]: info: Ignoring MPD Status Update Aug 26 10:49:52 volumio volumio[8439]: info: Aug 26 10:49:52 volumio volumio[8439]: ---------------------------- MPD announces system playlist update Aug 26 10:49:52 volumio volumio[8439]: info: Ignoring MPD Status Update Aug 26 10:49:52 volumio volumio[8439]: info: Aug 26 10:49:52 volumio volumio[8439]: ---------------------------- MPD announces state update: player Aug 26 10:49:52 volumio volumio[8439]: info: Aug 26 10:49:52 volumio volumio[8439]: ---------------------------- MPD announces state update: player Aug 26 10:49:52 volumio volumio[8439]: info: ------------------------------ 14ms Aug 26 10:49:52 volumio volumio[8439]: info: sendMpdCommand play took 9 milliseconds Aug 26 10:49:52 volumio volumio[8439]: info: ControllerMpd::getState Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand status Aug 26 10:49:52 volumio volumio[8439]: info: ------------------------------ 8ms Aug 26 10:49:52 volumio volumio[8439]: info: ControllerMpd::getState Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand status Aug 26 10:49:52 volumio volumio[8439]: info: ------------------------------ 7ms Aug 26 10:49:52 volumio volumio[8439]: info: Aug 26 10:49:52 volumio volumio[8439]: ---------------------------- MPD announces state update: player Aug 26 10:49:52 volumio volumio[8439]: info: ControllerMpd::getState Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand status Aug 26 10:49:52 volumio volumio[8439]: info: Aug 26 10:49:52 volumio volumio[8439]: ---------------------------- MPD announces state update: player Aug 26 10:49:52 volumio volumio[8439]: info: ControllerMpd::getState Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand status Aug 26 10:49:52 volumio volumio[8439]: info: sendMpdCommand status took 8 milliseconds Aug 26 10:49:52 volumio volumio[8439]: info: sendMpdCommand status took 8 milliseconds Aug 26 10:49:52 volumio volumio[8439]: info: sendMpdCommand status took 6 milliseconds Aug 26 10:49:52 volumio volumio[8439]: info: sendMpdCommand status took 3 milliseconds Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::parseState Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::parseState Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::parseState Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::parseState Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 10:49:52 volumio volumio[8439]: info: Aug 26 10:49:52 volumio volumio[8439]: ---------------------------- MPD announces state update: player Aug 26 10:49:52 volumio volumio[8439]: info: ControllerMpd::getState Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand status Aug 26 10:49:52 volumio volumio[8439]: info: Aug 26 10:49:52 volumio volumio[8439]: ---------------------------- MPD announces state update: player Aug 26 10:49:52 volumio volumio[8439]: info: ControllerMpd::getState Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand status Aug 26 10:49:52 volumio volumio[8439]: info: sendMpdCommand playlistinfo took 11 milliseconds Aug 26 10:49:52 volumio volumio[8439]: info: sendMpdCommand playlistinfo took 11 milliseconds Aug 26 10:49:52 volumio volumio[8439]: info: sendMpdCommand playlistinfo took 10 milliseconds Aug 26 10:49:52 volumio volumio[8439]: info: sendMpdCommand playlistinfo took 10 milliseconds Aug 26 10:49:52 volumio volumio[8439]: info: sendMpdCommand status took 6 milliseconds Aug 26 10:49:52 volumio volumio[8439]: info: sendMpdCommand status took 5 milliseconds Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::parseTrackInfo Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::parseTrackInfo Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::parseTrackInfo Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::parseTrackInfo Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::parseState Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::parseState Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::sendMpdCommand playlistinfo Aug 26 10:49:52 volumio volumio[8439]: info: ControllerMpd::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::servicePushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Akendora's Clock","artist":"Keiko Matsui","album":null,"uri":"INTERNAL/Fonovaya/04_Keiko_Matsui-Akendoras_Clock.mp3","trackType":"mp3"} Aug 26 10:49:52 volumio volumio[8439]: verbose: CURRENT POSITION 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::syncState stateService play Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::syncState currentStatus stop Aug 26 10:49:52 volumio volumio[8439]: info: ControllerMpd::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::servicePushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Akendora's Clock","artist":"Keiko Matsui","album":null,"uri":"INTERNAL/Fonovaya/04_Keiko_Matsui-Akendoras_Clock.mp3","trackType":"mp3"} Aug 26 10:49:52 volumio volumio[8439]: verbose: CURRENT POSITION 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::syncState stateService play Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::syncState currentStatus play Aug 26 10:49:52 volumio volumio[8439]: info: Received an update from plugin. extracting info from payload Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:52 volumio volumio[8439]: info: ControllerMpd::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::servicePushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Akendora's Clock","artist":"Keiko Matsui","album":null,"uri":"INTERNAL/Fonovaya/04_Keiko_Matsui-Akendoras_Clock.mp3","trackType":"mp3"} Aug 26 10:49:52 volumio volumio[8439]: verbose: CURRENT POSITION 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::syncState stateService play Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::syncState currentStatus play Aug 26 10:49:52 volumio volumio[8439]: info: Received an update from plugin. extracting info from payload Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:52 volumio volumio[8439]: info: ControllerMpd::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::servicePushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":298,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Akendora's Clock","artist":"Keiko Matsui","album":null,"uri":"INTERNAL/Fonovaya/04_Keiko_Matsui-Akendoras_Clock.mp3","trackType":"mp3"} Aug 26 10:49:52 volumio volumio[8439]: verbose: CURRENT POSITION 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::syncState stateService play Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::syncState currentStatus play Aug 26 10:49:52 volumio volumio[8439]: info: Received an update from plugin. extracting info from payload Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:52 volumio volumio[8439]: info: ------------------------------ 65ms Aug 26 10:49:52 volumio volumio[8439]: info: ------------------------------ 97ms Aug 26 10:49:52 volumio volumio[8439]: info: ------------------------------ 94ms Aug 26 10:49:52 volumio volumio[8439]: info: ------------------------------ 93ms Aug 26 10:49:52 volumio volumio[8439]: info: sendMpdCommand playlistinfo took 72 milliseconds Aug 26 10:49:52 volumio volumio[8439]: info: sendMpdCommand playlistinfo took 72 milliseconds Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::parseTrackInfo Aug 26 10:49:52 volumio volumio[8439]: verbose: ControllerMpd::parseTrackInfo Aug 26 10:49:52 volumio volumio[8439]: info: ControllerMpd::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::servicePushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: verbose: STATE SERVICE {"status":"play","position":0,"seek":982,"duration":298,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Akendora's Clock","artist":"Keiko Matsui","album":null,"uri":"INTERNAL/Fonovaya/04_Keiko_Matsui-Akendoras_Clock.mp3","trackType":"mp3"} Aug 26 10:49:52 volumio volumio[8439]: verbose: CURRENT POSITION 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::syncState stateService play Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::syncState currentStatus play Aug 26 10:49:52 volumio volumio[8439]: info: Received an update from plugin. extracting info from payload Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:52 volumio volumio[8439]: info: ControllerMpd::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::servicePushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: verbose: STATE SERVICE {"status":"play","position":0,"seek":982,"duration":298,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"320 Kbps","isStreaming":false,"title":"Akendora's Clock","artist":"Keiko Matsui","album":null,"uri":"INTERNAL/Fonovaya/04_Keiko_Matsui-Akendoras_Clock.mp3","trackType":"mp3"} Aug 26 10:49:52 volumio volumio[8439]: verbose: CURRENT POSITION 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::syncState stateService play Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::syncState currentStatus play Aug 26 10:49:52 volumio volumio[8439]: info: Received an update from plugin. extracting info from payload Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:52 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:49:52 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:49:52 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:49:52 volumio volumio[8439]: info: ------------------------------ 125ms Aug 26 10:49:52 volumio volumio[8439]: info: ------------------------------ 123ms Aug 26 10:49:52 volumio volumio[8439]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Aug 26 10:50:00 volumio volumio[8439]: error: MyVolumio Plugin failed to start in a timely fashion Aug 26 10:50:00 volumio volumio[8439]: [Metrics] CommandRouter: 27s 706.86ms Aug 26 10:50:00 volumio volumio[8439]: info: CoreCommandRouter::volumiosetStartupVolume Aug 26 10:50:00 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Aug 26 10:50:00 volumio volumio[8439]: info: VolumeController:: Setting startup Volume 40 Aug 26 10:50:00 volumio volumio[8439]: info: VolumeController::SetAlsaVolume40 Aug 26 10:50:00 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 10:50:00 volumio volumio[8439]: info: CoreCommandRouter::Close All Modals sent Aug 26 10:50:00 volumio volumio[8439]: info: CoreCommandRouter::Close All Modals sent Aug 26 10:50:00 volumio volumio[8439]: info: CoreStateMachine::pushState Aug 26 10:50:00 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:50:00 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 26 10:50:00 volumio volumio[8439]: info: CoreCommandRouter::volumioPushState Aug 26 10:50:01 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Aug 26 10:50:01 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Aug 26 10:50:01 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Aug 26 10:50:02 volumio volumio[8439]: info: Discovery: adding f4240e2a-484e-4c55-ad3f-ddacbb7a3ff8 Aug 26 10:50:02 volumio volumio[8439]: info: Discovery: Found device Volumio Aug 26 10:50:02 volumio volumio[8439]: info: CoreCommandRouter::volumioGetState Aug 26 10:50:02 volumio volumio[8439]: info: CorePlayQueue::getTrack 6 Aug 26 10:50:07 volumio volumio[8439]: info: BOOT COMPLETED Aug 26 10:50:08 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 26 10:50:08 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Aug 26 10:50:08 volumio volumio[8439]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 26 10:50:10 volumio volumio[8439]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 10:50:10 volumio volumio[8439]: Error: connect ECONNREFUSED 158.69.210.98:443 Aug 26 10:50:10 volumio volumio[8439]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Aug 26 10:50:10 volumio volumio[8439]: errno: -111, Aug 26 10:50:10 volumio volumio[8439]: code: 'ECONNREFUSED', Aug 26 10:50:10 volumio volumio[8439]: syscall: 'connect', Aug 26 10:50:10 volumio volumio[8439]: address: '158.69.210.98', Aug 26 10:50:10 volumio volumio[8439]: port: 443 Aug 26 10:50:10 volumio volumio[8439]: } Aug 26 10:50:10 volumio volumio[8439]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 26 10:50:11 volumio sudo[8754]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-08-26 10:49 Aug 26 10:50:11 volumio sudo[8754]: 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="e9612ec5034fb2e958508aaefbca2962fd6f6654" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="464fc672d77d3df6ee72b331d36cdf1fa936e1ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 27 Feb 2026 10:59:40 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="37c6ab864cb114e1344d540995c69f86"