Sep 13 11:23:00 volumio volumio[22694]: info: CoreCommandRouter::volumioGetState
Sep 13 11:23:00 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:00 volumio volumio[22694]: info: CoreCommandRouter::volumioGetState
Sep 13 11:23:00 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:00 volumio sudo[22906]: pam_unix(sudo:session): session closed for user root
Sep 13 11:23:00 volumio volumio[22694]: info: touch_display: systemctl stop getty@tty1.service succeeded.
Sep 13 11:23:00 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Sep 13 11:23:00 volumio sudo[22950]: pam_unix(sudo:session): session closed for user root
Sep 13 11:23:00 volumio sudo[22954]: pam_unix(sudo:session): session closed for user root
Sep 13 11:23:00 volumio sudo[22948]: pam_unix(sudo:session): session closed for user root
Sep 13 11:23:00 volumio volumio[22694]: info: Shairport-Sync Started
Sep 13 11:23:00 volumio volumio[22694]: Error adding Membership: Error: addMembership EINVAL
Sep 13 11:23:00 volumio volumio[22694]: info: Shairport-Sync Started
Sep 13 11:23:00 volumio sudo[22986]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Sep 13 11:23:00 volumio sudo[22986]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Sep 13 11:23:00 volumio volumio[22694]: info: Shairport-Sync Started
Sep 13 11:23:00 volumio sudo[22986]: pam_unix(sudo:session): session closed for user root
Sep 13 11:23:00 volumio volumio[22694]: info: touch_display: X display number found: 0
Sep 13 11:23:00 volumio volumio[22694]: info: touch_display: X display number found: 0
Sep 13 11:23:00 volumio volumio[22694]: info: touch_display: Using Xserver unix domain socket /tmp/.X11-unix/X0
Sep 13 11:23:00 volumio volumio[22694]: info: touch_display: X display number found: 0
Sep 13 11:23:00 volumio volumio[22694]: info: touch_display: Setting screensaver timeout to 0 seconds.
Sep 13 11:23:05 volumio mpd[22993]: 2025-09-13T11:23:05 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Sep 13 11:23:05 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Sep 13 11:23:05 volumio sudo[22866]: pam_unix(sudo:session): session closed for user root
Sep 13 11:23:05 volumio sudo[22856]: pam_unix(sudo:session): session closed for user root
Sep 13 11:23:05 volumio volumio[22694]: info: Completed starting Core Plugins
Sep 13 11:23:05 volumio volumio[22694]: info: -------------------------------------------
Sep 13 11:23:05 volumio volumio[22694]: info: ----- MyVolumio plugins startup ----
Sep 13 11:23:05 volumio volumio[22694]: info: -------------------------------------------
Sep 13 11:23:05 volumio volumio[22694]: info: [MyVolumio PluginManager] Fetching plans data....
Sep 13 11:23:05 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service...
Sep 13 11:23:05 volumio dbus-daemon[564]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.177' (uid=0 pid=23037 comm="timedatectl show --property=NTPSynchronized --valu")
Sep 13 11:23:05 volumio volumio[22694]: error: MPD error: The expression evaluated to a falsy value:
Sep 13 11:23:05 volumio volumio[22694]: assert.ok(self.idling)
Sep 13 11:23:05 volumio volumio[22694]: error: The expression evaluated to a falsy value:
Sep 13 11:23:05 volumio volumio[22694]: assert.ok(self.idling)
Sep 13 11:23:05 volumio volumio[22694]: info: MPD running with PID22993
Sep 13 11:23:05 volumio volumio[22694]: ,establishing connection
Sep 13 11:23:05 volumio volumio[22694]: error: updateQueue error: null
Sep 13 11:23:05 volumio volumio[22694]: error: updateQueue error: null
Sep 13 11:23:05 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service...
Sep 13 11:23:06 volumio dbus-daemon[564]: [system] Successfully activated service 'org.freedesktop.timedate1'
Sep 13 11:23:06 volumio systemd[1]: Started systemd-timedated.service - Time & Date Service.
Sep 13 11:23:06 volumio setdatetime-helper.sh[23032]: Time is already synchronized.
Sep 13 11:23:06 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully.
Sep 13 11:23:06 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service.
Sep 13 11:23:10 volumio volumio[22694]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Sep 13 11:23:13 volumio volumio[22694]: info: Adding plugin bluetooth to MyMusic Plugins
Sep 13 11:23:13 volumio volumio[22694]: info: Adding plugin multiroom to MyMusic Plugins
Sep 13 11:23:13 volumio volumio[22694]: info: Adding plugin metavolumio to MyMusic Plugins
Sep 13 11:23:13 volumio volumio[22694]: info: Adding plugin cd_controller to MyMusic Plugins
Sep 13 11:23:13 volumio volumio[22694]: info: Adding plugin smart_inputs to MyMusic Plugins
Sep 13 11:23:13 volumio volumio[22694]: info: Adding plugin tidalconnect to MyMusic Plugins
Sep 13 11:23:13 volumio volumio[22694]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Sep 13 11:23:15 volumio volumio[22694]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Sep 13 11:23:15 volumio volumio[22694]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Sep 13 11:23:15 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:23:15 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:23:15 volumio volumio[22694]: info: Starting MyVolumio Remote Streaming Endpoints
Sep 13 11:23:15 volumio volumio[22694]: info: MyVolumio login type: Token
Sep 13 11:23:15 volumio volumio[22694]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Sep 13 11:23:15 volumio volumio[22694]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Sep 13 11:23:16 volumio volumio[22694]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Sep 13 11:23:16 volumio volumio[22694]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Sep 13 11:23:16 volumio volumio[22694]: info: Streaming services startup
Sep 13 11:23:16 volumio volumio[22694]: info: Starting Streaming Daemon
Sep 13 11:23:16 volumio volumio[22694]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Sep 13 11:23:16 volumio sudo[23059]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Sep 13 11:23:16 volumio sudo[23059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:23:16 volumio sudo[23059]: pam_unix(sudo:session): session closed for user root
Sep 13 11:23:16 volumio volumio[22694]: error: Cannot start Volumio Streaming Daemon
Sep 13 11:23:16 volumio volumio[22694]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Sep 13 11:23:16 volumio volumio[22694]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Sep 13 11:23:17 volumio volumio[22694]: error: MyVolumio Custom Token format not valid, refreshing it
Sep 13 11:23:17 volumio volumio[22694]: info: MyVolumio login type: Token
Sep 13 11:23:18 volumio volumio[22694]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Sep 13 11:23:19 volumio volumio[22694]: info: MyVolumio token set successfully
Sep 13 11:23:19 volumio volumio[22694]: info: MYVOLUMIO: Adding device
Sep 13 11:23:19 volumio volumio[22694]: info: MYVOLUMIO: Evaluating Server
Sep 13 11:23:19 volumio volumio[22694]: info: MyVolumio status changed
Sep 13 11:23:19 volumio volumio[22694]: info: Streaming services startup
Sep 13 11:23:19 volumio volumio[22694]: info: Starting Streaming Daemon
Sep 13 11:23:19 volumio volumio[22694]: info: Removing browser output: myVolumio user plan is not superstar
Sep 13 11:23:19 volumio volumio[22694]: info: Removing audio output:
Sep 13 11:23:19 volumio volumio[22694]: info: Stoppping Tunnel 1
Sep 13 11:23:19 volumio sudo[23084]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Sep 13 11:23:19 volumio sudo[23084]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:23:19 volumio sudo[23086]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Sep 13 11:23:19 volumio sudo[23086]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:23:19 volumio sudo[23084]: pam_unix(sudo:session): session closed for user root
Sep 13 11:23:19 volumio volumio[22694]: error: Cannot start Volumio Streaming Daemon
Sep 13 11:23:19 volumio volumio[22694]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Sep 13 11:23:19 volumio volumio[22694]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Sep 13 11:23:19 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 13 11:23:19 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 13 11:23:19 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 13 11:23:19 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 13 11:23:19 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 13 11:23:19 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 13 11:23:19 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 13 11:23:19 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether.
Sep 13 11:23:19 volumio sudo[23086]: pam_unix(sudo:session): session closed for user root
Sep 13 11:23:19 volumio volumio[22694]: info: Remote SSH Stopped
Sep 13 11:23:20 volumio volumio[22694]: info: Setting Geolocation for MyVolumio to eu2
Sep 13 11:23:20 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:23:20 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:23:20 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:23:20 volumio volumio[22694]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Sep 13 11:23:21 volumio volumio[22694]: info: Updating MyVolumio device info
Sep 13 11:23:21 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:23:21 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:23:21 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:23:21 volumio volumio[22694]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Sep 13 11:23:22 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri
Sep 13 11:23:22 volumio volumio[22694]: info: Preload queue cleared
Sep 13 11:23:22 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Sep 13 11:23:22 volumio volumio[22694]: info: Received Get System Info
Sep 13 11:23:22 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 13 11:23:22 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 13 11:23:22 volumio volumio[22694]: info: Discovery: Getting this device information
Sep 13 11:23:22 volumio volumio[22694]: info: CoreCommandRouter::volumioGetState
Sep 13 11:23:22 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:22 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 13 11:23:24 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 13 11:23:24 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:23:24 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Sep 13 11:23:24 volumio volumio[22694]: info: MYVOLUMIO: Adding device
Sep 13 11:23:24 volumio volumio[22694]: info: MYVOLUMIO: Evaluating Server
Sep 13 11:23:24 volumio volumio-remote-updater[585]: No test mode
Sep 13 11:23:24 volumio volumio-remote-updater[585]: No alpha test mode
Sep 13 11:23:24 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Sep 13 11:23:24 volumio volumio[22694]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false}
Sep 13 11:23:24 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Sep 13 11:23:24 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri
Sep 13 11:23:24 volumio volumio[22694]: info: TuneIn handleBrowseUri: tunein/local
Sep 13 11:23:24 volumio volumio[22694]: info: Preload queue cleared
Sep 13 11:23:24 volumio volumio[22694]: info: Preload queue cleared
Sep 13 11:23:25 volumio volumio[22694]: info: Setting Geolocation for MyVolumio to eu5
Sep 13 11:23:25 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:23:25 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:23:25 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:23:25 volumio volumio[22694]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Sep 13 11:23:26 volumio volumio[22694]: info: Updating MyVolumio device info
Sep 13 11:23:26 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:23:26 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:23:26 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:23:27 volumio volumio[22694]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Sep 13 11:23:29 volumio volumio[22694]: info: Preload queue cleared
Sep 13 11:23:29 volumio volumio[22694]: info: CoreCommandRouter::volumioReplaceandPlayItems
Sep 13 11:23:29 volumio volumio[22694]: info: CoreStateMachine::ClearQueue
Sep 13 11:23:29 volumio volumio[22694]: info: CoreStateMachine::stop
Sep 13 11:23:29 volumio volumio[22694]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 13 11:23:29 volumio volumio[22694]: info: CorePlayQueue::clearPlayQueue
Sep 13 11:23:29 volumio volumio[22694]: info: CorePlayQueue::saveQueue
Sep 13 11:23:29 volumio volumio[22694]: info: CoreCommandRouter::volumioPushQueue
Sep 13 11:23:29 volumio volumio[22694]: info: CoreStateMachine::addQueueItems
Sep 13 11:23:29 volumio volumio[22694]: info: CorePlayQueue::addQueueItems
Sep 13 11:23:29 volumio volumio[22694]: info: Preload queue cleared
Sep 13 11:23:29 volumio volumio[22694]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s260759
Sep 13 11:23:29 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Sep 13 11:23:29 volumio volumio[22694]: info: CoreCommandRouter::volumioPushQueue
Sep 13 11:23:29 volumio volumio[22694]: info: CorePlayQueue::saveQueue
Sep 13 11:23:29 volumio volumio[22694]: info: CoreStateMachine::updateTrackBlock
Sep 13 11:23:29 volumio volumio[22694]: info: CorePlayQueue::getTrackBlock
Sep 13 11:23:29 volumio volumio[22694]: info: CoreCommandRouter::volumioPlay
Sep 13 11:23:29 volumio volumio[22694]: info: CoreStateMachine::play index 0
Sep 13 11:23:29 volumio volumio[22694]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 13 11:23:29 volumio volumio[22694]: info: CoreStateMachine::stop
Sep 13 11:23:29 volumio volumio[22694]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 13 11:23:29 volumio volumio[22694]: info: CoreStateMachine::play index undefined
Sep 13 11:23:29 volumio volumio[22694]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 13 11:23:29 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:29 volumio volumio[22694]: info: CoreStateMachine::startPlaybackTimer
Sep 13 11:23:29 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:29 volumio volumio[22694]: info: [1757755409460] ControllerWebradio::clearAddPlayTrack
Sep 13 11:23:29 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand stop
Sep 13 11:23:29 volumio volumio[22694]: info: sendMpdCommand stop took 5 milliseconds
Sep 13 11:23:29 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand clear
Sep 13 11:23:29 volumio volumio[22694]: info: sendMpdCommand clear took 1 milliseconds
Sep 13 11:23:29 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand load "https://mcp-2.mm-stream.nl:8000/stream"
Sep 13 11:23:29 volumio volumio[22694]: info:
Sep 13 11:23:29 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:29 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:29 volumio volumio[22694]: info:
Sep 13 11:23:29 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:29 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:29 volumio volumio[22694]: info:
Sep 13 11:23:29 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:29 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:30 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Sep 13 11:23:30 volumio volumio[22694]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 13
Sep 13 11:23:30 volumio volumio[22694]: error: updateQueue error: null
Sep 13 11:23:30 volumio volumio[22694]: error: updateQueue error: null
Sep 13 11:23:30 volumio volumio[22694]: error: updateQueue error: null
Sep 13 11:23:30 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand add "https://mcp-2.mm-stream.nl:8000/stream"
Sep 13 11:23:30 volumio volumio[22694]: info: ------------------------------ 923ms
Sep 13 11:23:30 volumio volumio[22694]: info: ------------------------------ 921ms
Sep 13 11:23:30 volumio volumio[22694]: info: ------------------------------ 919ms
Sep 13 11:23:30 volumio volumio[22694]: info:
Sep 13 11:23:30 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:30 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:30 volumio volumio[22694]: info: sendMpdCommand add "https://mcp-2.mm-stream.nl:8000/stream" took 5 milliseconds
Sep 13 11:23:30 volumio volumio[22694]: info: CoreStateMachine::setConsumeUpdateService mpd
Sep 13 11:23:30 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand play
Sep 13 11:23:30 volumio volumio[22694]: info:
Sep 13 11:23:30 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:30 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:30 volumio volumio[22694]: info:
Sep 13 11:23:30 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:30 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:30 volumio volumio[22694]: info: ------------------------------ 14ms
Sep 13 11:23:30 volumio volumio[22694]: info: sendMpdCommand play took 12 milliseconds
Sep 13 11:23:30 volumio volumio[22694]: info: ------------------------------ 10ms
Sep 13 11:23:30 volumio volumio[22694]: info: ------------------------------ 8ms
Sep 13 11:23:30 volumio volumio[22694]: info: CoreCommandRouter::volumioGetState
Sep 13 11:23:31 volumio volumio[22694]: info:
Sep 13 11:23:31 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:31 volumio volumio[22694]: info:
Sep 13 11:23:31 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:31 volumio volumio[22694]: info:
Sep 13 11:23:31 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:31 volumio volumio[22694]: info:
Sep 13 11:23:31 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand status took 28 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand status took 27 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand status took 18 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:31 volumio volumio[22694]: info:
Sep 13 11:23:31 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:31 volumio volumio[22694]: info:
Sep 13 11:23:31 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:31 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:31 volumio volumio[22694]: info:
Sep 13 11:23:31 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:31 volumio volumio[22694]: info:
Sep 13 11:23:31 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:31 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:31 volumio volumio[22694]: info:
Sep 13 11:23:31 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand status took 18 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 14 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 13 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 13 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand status took 9 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:31 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:31 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Spice Girls - Spice Up Your Life","artist":"HETE HITS - www.hetehits.nu","album":null,"uri":"https://mcp-2.mm-stream.nl:8000/stream","trackType":""}
Sep 13 11:23:31 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus stop
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:31 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:31 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Spice Girls - Spice Up Your Life","artist":"HETE HITS - www.hetehits.nu","album":null,"uri":"https://mcp-2.mm-stream.nl:8000/stream","trackType":""}
Sep 13 11:23:31 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:31 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:31 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:31 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Spice Girls - Spice Up Your Life","artist":"HETE HITS - www.hetehits.nu","album":null,"uri":"https://mcp-2.mm-stream.nl:8000/stream","trackType":""}
Sep 13 11:23:31 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:31 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: ------------------------------ 87ms
Sep 13 11:23:31 volumio volumio[22694]: info: ------------------------------ 127ms
Sep 13 11:23:31 volumio volumio[22694]: info: ------------------------------ 126ms
Sep 13 11:23:31 volumio volumio[22694]: info:
Sep 13 11:23:31 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:31 volumio volumio[22694]: info:
Sep 13 11:23:31 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:31 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:31 volumio volumio[22694]: info:
Sep 13 11:23:31 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:31 volumio volumio[22694]: info: ------------------------------ 99ms
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand status took 94 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: info: ------------------------------ 99ms
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand status took 94 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 91 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 87 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand status took 11 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: info: ------------------------------ 10ms
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:31 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:31 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":979,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"Spice Girls - Spice Up Your Life","artist":"HETE HITS - www.hetehits.nu","album":null,"uri":"https://mcp-2.mm-stream.nl:8000/stream","trackType":""}
Sep 13 11:23:31 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:31 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:31 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:31 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":979,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"Spice Girls - Spice Up Your Life","artist":"HETE HITS - www.hetehits.nu","album":null,"uri":"https://mcp-2.mm-stream.nl:8000/stream","trackType":""}
Sep 13 11:23:31 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:31 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: ------------------------------ 219ms
Sep 13 11:23:31 volumio volumio[22694]: info: ------------------------------ 207ms
Sep 13 11:23:31 volumio volumio[22694]: info:
Sep 13 11:23:31 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:31 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:31 volumio volumio[22694]: info:
Sep 13 11:23:31 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand status took 203 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 196 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 195 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 195 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: info: ------------------------------ 95ms
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand status took 92 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:31 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:31 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":979,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"Spice Girls - Spice Up Your Life","artist":"HETE HITS - www.hetehits.nu","album":null,"uri":"https://mcp-2.mm-stream.nl:8000/stream","trackType":""}
Sep 13 11:23:31 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:31 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:31 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:31 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":979,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"Spice Girls - Spice Up Your Life","artist":"HETE HITS - www.hetehits.nu","album":null,"uri":"https://mcp-2.mm-stream.nl:8000/stream","trackType":""}
Sep 13 11:23:31 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:31 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:31 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:31 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":979,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"Spice Girls - Spice Up Your Life","artist":"HETE HITS - www.hetehits.nu","album":null,"uri":"https://mcp-2.mm-stream.nl:8000/stream","trackType":""}
Sep 13 11:23:31 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:31 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: ------------------------------ 448ms
Sep 13 11:23:31 volumio volumio[22694]: info: ------------------------------ 448ms
Sep 13 11:23:31 volumio volumio[22694]: info: ------------------------------ 363ms
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 150 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 144 milliseconds
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:31 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:31 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:31 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":979,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"Spice Girls - Spice Up Your Life","artist":"HETE HITS - www.hetehits.nu","album":null,"uri":"https://mcp-2.mm-stream.nl:8000/stream","trackType":""}
Sep 13 11:23:31 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:31 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:31 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:31 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1105,"duration":0,"samplerate":"48 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"Spice Girls - Spice Up Your Life","artist":"HETE HITS - www.hetehits.nu","album":null,"uri":"https://mcp-2.mm-stream.nl:8000/stream","trackType":""}
Sep 13 11:23:31 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:31 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:31 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:31 volumio volumio[22694]: info: ------------------------------ 456ms
Sep 13 11:23:31 volumio volumio[22694]: info: ------------------------------ 345ms
Sep 13 11:23:34 volumio volumio[22694]: info: Preload queue cleared
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::volumioReplaceandPlayItems
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::ClearQueue
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::stop
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::stPlaybackTimer
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::updateTrackBlock
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrackBlock
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::serviceStop
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::serviceStop
Sep 13 11:23:34 volumio volumio[22694]: info: [1757755414250] ControllerWebradio::stop
Sep 13 11:23:34 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand stop
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::clearPlayQueue
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::saveQueue
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::volumioPushQueue
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::addQueueItems
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::addQueueItems
Sep 13 11:23:34 volumio volumio[22694]: info: Preload queue cleared
Sep 13 11:23:34 volumio volumio[22694]: info: Adding Item to queue: http://opml.radiotime.com/Tune.ashx?id=s261741
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: webradio , explodeUri
Sep 13 11:23:34 volumio volumio[22694]: info:
Sep 13 11:23:34 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:34 volumio volumio[22694]: info: sendMpdCommand stop took 57 milliseconds
Sep 13 11:23:34 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:34 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:34 volumio volumio[22694]: info: sendMpdCommand status took 2 milliseconds
Sep 13 11:23:34 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:34 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:34 volumio volumio[22694]: info:
Sep 13 11:23:34 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:34 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:34 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:34 volumio volumio[22694]: info:
Sep 13 11:23:34 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:34 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:34 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:34 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 18 milliseconds
Sep 13 11:23:34 volumio volumio[22694]: info: sendMpdCommand status took 16 milliseconds
Sep 13 11:23:34 volumio volumio[22694]: info: sendMpdCommand status took 15 milliseconds
Sep 13 11:23:34 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:34 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:34 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:34 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:34 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:34 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:34 volumio volumio[22694]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Spice Girls - Spice Up Your Life","artist":"HETE HITS - www.hetehits.nu","album":null,"uri":"https://mcp-2.mm-stream.nl:8000/stream","trackType":""}
Sep 13 11:23:34 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::syncState stateService stop
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus stop
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:34 volumio volumio[22694]: info: No code
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:34 volumio volumio[22694]: info: ------------------------------ 104ms
Sep 13 11:23:34 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 76 milliseconds
Sep 13 11:23:34 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 76 milliseconds
Sep 13 11:23:34 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:34 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:34 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:34 volumio volumio[22694]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Spice Girls - Spice Up Your Life","artist":"HETE HITS - www.hetehits.nu","album":null,"uri":"https://mcp-2.mm-stream.nl:8000/stream","trackType":""}
Sep 13 11:23:34 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::syncState stateService stop
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus stop
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:34 volumio volumio[22694]: info: No code
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:34 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:34 volumio volumio[22694]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Spice Girls - Spice Up Your Life","artist":"HETE HITS - www.hetehits.nu","album":null,"uri":"https://mcp-2.mm-stream.nl:8000/stream","trackType":""}
Sep 13 11:23:34 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::syncState stateService stop
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus stop
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:34 volumio volumio[22694]: info: No code
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:34 volumio volumio[22694]: info: ------------------------------ 241ms
Sep 13 11:23:34 volumio volumio[22694]: info: ------------------------------ 240ms
Sep 13 11:23:34 volumio volumio[22694]: info: touch_display: Setting screensaver timeout to 0 seconds.
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::volumioPushQueue
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::saveQueue
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::updateTrackBlock
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrackBlock
Sep 13 11:23:34 volumio volumio[22694]: info: CoreCommandRouter::volumioPlay
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::play index 0
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::stop
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::play index undefined
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::setConsumeUpdateService undefined
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:34 volumio volumio[22694]: info: CoreStateMachine::startPlaybackTimer
Sep 13 11:23:34 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:34 volumio volumio[22694]: info: [1757755414683] ControllerWebradio::clearAddPlayTrack
Sep 13 11:23:34 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand stop
Sep 13 11:23:34 volumio volumio[22694]: info: sendMpdCommand stop took 10 milliseconds
Sep 13 11:23:34 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand clear
Sep 13 11:23:34 volumio volumio[22694]: info:
Sep 13 11:23:34 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:34 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:34 volumio volumio[22694]: info: sendMpdCommand clear took 4 milliseconds
Sep 13 11:23:34 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand load "http://stream.joyradio.nl/joyradio"
Sep 13 11:23:34 volumio volumio[22694]: info:
Sep 13 11:23:34 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:34 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:34 volumio volumio[22694]: info:
Sep 13 11:23:34 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:34 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:34 volumio volumio[22694]: error: updateQueue error: null
Sep 13 11:23:34 volumio volumio[22694]: info: ------------------------------ 14ms
Sep 13 11:23:35 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:23:35 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:23:35 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Sep 13 11:23:35 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Sep 13 11:23:35 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Sep 13 11:23:35 volumio volumio[22694]: info: CoreCommandRouter::volumioGetBrowseSources
Sep 13 11:23:35 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 13 11:23:35 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand add "http://stream.joyradio.nl/joyradio"
Sep 13 11:23:35 volumio volumio[22694]: error: updateQueue error: null
Sep 13 11:23:35 volumio volumio[22694]: error: updateQueue error: null
Sep 13 11:23:35 volumio volumio[22694]: info:
Sep 13 11:23:35 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:35 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:35 volumio volumio[22694]: info: ------------------------------ 853ms
Sep 13 11:23:35 volumio volumio[22694]: info: ------------------------------ 850ms
Sep 13 11:23:35 volumio volumio[22694]: info: sendMpdCommand add "http://stream.joyradio.nl/joyradio" took 4 milliseconds
Sep 13 11:23:35 volumio volumio[22694]: info: CoreStateMachine::setConsumeUpdateService mpd
Sep 13 11:23:35 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand play
Sep 13 11:23:35 volumio volumio[22694]: info:
Sep 13 11:23:35 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:35 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:35 volumio volumio[22694]: info:
Sep 13 11:23:35 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:35 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:35 volumio volumio[22694]: info: ------------------------------ 8ms
Sep 13 11:23:35 volumio volumio[22694]: info: sendMpdCommand play took 6 milliseconds
Sep 13 11:23:35 volumio volumio[22694]: info: ------------------------------ 5ms
Sep 13 11:23:35 volumio volumio[22694]: info: ------------------------------ 3ms
Sep 13 11:23:36 volumio systemd[1]: systemd-timedated.service: Deactivated successfully.
Sep 13 11:23:36 volumio volumio[22694]: info:
Sep 13 11:23:36 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:36 volumio volumio[22694]: info:
Sep 13 11:23:36 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:36 volumio volumio[22694]: info:
Sep 13 11:23:36 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:36 volumio volumio[22694]: info:
Sep 13 11:23:36 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand status took 6 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand status took 7 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:36 volumio volumio[22694]: info:
Sep 13 11:23:36 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:36 volumio volumio[22694]: info:
Sep 13 11:23:36 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand status took 12 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand status took 8 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 7 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 6 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand status took 5 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand status took 3 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"joyradio","artist":null,"album":null,"uri":"http://stream.joyradio.nl/joyradio","trackType":""}
Sep 13 11:23:36 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus stop
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"joyradio","artist":null,"album":null,"uri":"http://stream.joyradio.nl/joyradio","trackType":""}
Sep 13 11:23:36 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:36 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:36 volumio volumio[22694]: info: ------------------------------ 46ms
Sep 13 11:23:36 volumio volumio[22694]: info: ------------------------------ 66ms
Sep 13 11:23:36 volumio volumio[22694]: info:
Sep 13 11:23:36 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:36 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:36 volumio volumio[22694]: info:
Sep 13 11:23:36 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:36 volumio volumio[22694]: info:
Sep 13 11:23:36 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:36 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:36 volumio volumio[22694]: info:
Sep 13 11:23:36 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:36 volumio volumio[22694]: info:
Sep 13 11:23:36 volumio volumio[22694]: ---------------------------- MPD announces system playlist update
Sep 13 11:23:36 volumio volumio[22694]: info: Ignoring MPD Status Update
Sep 13 11:23:36 volumio volumio[22694]: info:
Sep 13 11:23:36 volumio volumio[22694]: ---------------------------- MPD announces state update: player
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 61 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 62 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::getState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand status
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 62 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 63 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: info: ------------------------------ 18ms
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand status took 15 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: info: ------------------------------ 15ms
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"joyradio","artist":null,"album":null,"uri":"http://stream.joyradio.nl/joyradio","trackType":""}
Sep 13 11:23:36 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:36 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"joyradio","artist":null,"album":null,"uri":"http://stream.joyradio.nl/joyradio","trackType":""}
Sep 13 11:23:36 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:36 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"joyradio","artist":"JOY RADIO","album":null,"uri":"http://stream.joyradio.nl/joyradio","trackType":""}
Sep 13 11:23:36 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:36 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"joyradio","artist":"JOY RADIO","album":null,"uri":"http://stream.joyradio.nl/joyradio","trackType":""}
Sep 13 11:23:36 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:36 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:36 volumio volumio[22694]: info: ------------------------------ 228ms
Sep 13 11:23:36 volumio volumio[22694]: info: ------------------------------ 228ms
Sep 13 11:23:36 volumio volumio[22694]: info: ------------------------------ 221ms
Sep 13 11:23:36 volumio volumio[22694]: info: ------------------------------ 221ms
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand status took 237 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: info: ------------------------------ 236ms
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand status took 230 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 222 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseState
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":984,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"joyradio","artist":"JOY RADIO","album":null,"uri":"http://stream.joyradio.nl/joyradio","trackType":""}
Sep 13 11:23:36 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:36 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:36 volumio volumio[22694]: info: ------------------------------ 287ms
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 43 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: info: sendMpdCommand playlistinfo took 42 milliseconds
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:36 volumio volumio[22694]: verbose: ControllerMpd::parseTrackInfo
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":984,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"joyradio","artist":"JOY RADIO","album":null,"uri":"http://stream.joyradio.nl/joyradio","trackType":""}
Sep 13 11:23:36 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:36 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:36 volumio volumio[22694]: info: ControllerMpd::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::servicePushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: verbose: STATE SERVICE {"status":"play","position":0,"seek":984,"duration":0,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"joyradio","artist":"JOY RADIO","album":null,"uri":"http://stream.joyradio.nl/joyradio","trackType":""}
Sep 13 11:23:36 volumio volumio[22694]: verbose: CURRENT POSITION 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState stateService play
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::syncState currentStatus play
Sep 13 11:23:36 volumio volumio[22694]: info: Received an update from plugin. extracting info from payload
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CorePlayQueue::getTrack 0
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:36 volumio volumio[22694]: info: ------------------------------ 380ms
Sep 13 11:23:36 volumio volumio[22694]: info: ------------------------------ 378ms
Sep 13 11:23:36 volumio volumio[22694]: error: MyVolumio Plugin failed to authenticate in a timely fashion
Sep 13 11:23:36 volumio volumio[22694]: info: Completed starting MyVolumio Plugin
Sep 13 11:23:36 volumio volumio[22694]: [Metrics] CommandRouter: 58s 148.52ms
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumiosetStartupVolume
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:23:36 volumio volumio[22694]: info: VolumeController:: Setting startup Volume 75
Sep 13 11:23:36 volumio volumio[22694]: info: VolumeController::SetAlsaVolume75
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::Close All Modals sent
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::Close All Modals sent
Sep 13 11:23:36 volumio volumio[22694]: info: CoreStateMachine::pushState
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 13 11:23:36 volumio volumio[22694]: info: CoreCommandRouter::volumioPushState
Sep 13 11:23:37 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Sep 13 11:23:37 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Sep 13 11:23:38 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Sep 13 11:23:42 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: webradio , handleBrowseUri
Sep 13 11:23:42 volumio volumio[22694]: info: Preload queue cleared
Sep 13 11:23:43 volumio volumio[22694]: info: BOOT COMPLETED
Sep 13 11:23:46 volumio volumio[22694]: Searching plugin music_service/webradio
Sep 13 11:23:46 volumio volumio[22694]: info: CoreCommandRouter::executeOnPlugin: webradio , search
Sep 13 11:23:47 volumio volumio[22694]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 13 11:23:47 volumio volumio[22694]: TypeError: Cannot read properties of undefined (reading 'length')
Sep 13 11:23:47 volumio volumio[22694]: at /volumio/node_modules/libxmljs/dist/lib/parse.js:186:126
Sep 13 11:23:47 volumio volumio[22694]: at Object.parseXml (/volumio/node_modules/libxmljs/dist/lib/parse.js:185:49)
Sep 13 11:23:47 volumio volumio[22694]: at /volumio/app/plugins/music_service/webradio/index.js:949:31
Sep 13 11:23:47 volumio volumio[22694]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Sep 13 11:23:47 volumio volumio[22694]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 13 11:23:47 volumio sudo[23219]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-09-13 11:22'
Sep 13 11:23:47 volumio sudo[23219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:23:48 volumio sudo[23219]: pam_unix(sudo:session): session closed for user root
Sep 13 11:23:48 volumio volumio-remote-updater[585]: [2025-09-13 11:23:48] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Sep 13 11:23:48 volumio volumio-remote-updater[585]: [2025-09-13 11:23:48] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Sep 13 11:23:48 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Sep 13 11:23:48 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Sep 13 11:23:48 volumio systemd[1]: volumio.service: Consumed 41.660s CPU time.
Sep 13 11:23:48 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Sep 13 11:23:48 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Sep 13 11:23:48 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 2.
Sep 13 11:23:48 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Sep 13 11:23:48 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Sep 13 11:23:48 volumio systemd[1]: volumio.service: Consumed 41.660s CPU time.
Sep 13 11:23:48 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Sep 13 11:23:48 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Sep 13 11:23:51 volumio volumio[23245]: info: -------------------------------------------
Sep 13 11:23:51 volumio volumio[23245]: info: ----- Volumio3 ----
Sep 13 11:23:51 volumio volumio[23245]: info: -------------------------------------------
Sep 13 11:23:51 volumio volumio[23245]: info: ----- System startup ----
Sep 13 11:23:51 volumio volumio[23245]: info: -------------------------------------------
Sep 13 11:23:52 volumio volumio[23245]: info: MYVOLUMIO Environment detected
Sep 13 11:23:52 volumio volumio[23245]: info: Plugin folders cleanup
Sep 13 11:23:52 volumio volumio[23245]: info: Scanning into folder /volumio/app/plugins/
Sep 13 11:23:52 volumio volumio[23245]: info: Scanning category audio_interface
Sep 13 11:23:52 volumio volumio[23245]: info: Scanning category miscellanea
Sep 13 11:23:52 volumio volumio[23245]: info: Scanning category music_service
Sep 13 11:23:52 volumio volumio[23245]: info: Scanning category plugins.json
Sep 13 11:23:52 volumio volumio[23245]: info: Scanning category system_controller
Sep 13 11:23:52 volumio volumio[23245]: info: Scanning category user_interface
Sep 13 11:23:52 volumio volumio[23245]: info: Scanning into folder /data/plugins/
Sep 13 11:23:52 volumio volumio[23245]: info: Scanning category music_service
Sep 13 11:23:52 volumio volumio[23245]: info: Scanning category user_interface
Sep 13 11:23:52 volumio volumio[23245]: info: Plugin folders cleanup completed
Sep 13 11:23:52 volumio volumio[23245]: info: -------------------------------------------
Sep 13 11:23:52 volumio volumio[23245]: info: ----- Core plugins startup ----
Sep 13 11:23:52 volumio volumio[23245]: info: -------------------------------------------
Sep 13 11:23:52 volumio volumio[23245]: info: Loading plugins from folder /volumio/app/plugins/
Sep 13 11:23:52 volumio volumio[23245]: info: Adding plugin upnp to MyMusic Plugins
Sep 13 11:23:52 volumio volumio[23245]: info: Adding plugin airplay_emulation to MyMusic Plugins
Sep 13 11:23:52 volumio volumio[23245]: info: Adding plugin upnp_browser to MyMusic Plugins
Sep 13 11:23:52 volumio volumio[23245]: info: Loading plugins from folder /data/plugins/
Sep 13 11:23:52 volumio volumio[23245]: info: Loading plugin "system"...
Sep 13 11:23:52 volumio volumio[23245]: info: Loading plugin "appearance"...
Sep 13 11:23:53 volumio volumio-remote-updater[585]: [2025-09-13 11:23:53] [connect] Successful connection
Sep 13 11:23:54 volumio volumio[23245]: info: Loading plugin "network"...
Sep 13 11:23:54 volumio volumio[23245]: info: Refreshing Cached IP Addresses
Sep 13 11:23:54 volumio sudo[23273]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Sep 13 11:23:54 volumio sudo[23273]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:23:54 volumio sudo[23273]: pam_unix(sudo:session): session closed for user root
Sep 13 11:23:54 volumio sudo[23275]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 13 11:23:54 volumio volumio[23245]: info: Loading plugin "services"...
Sep 13 11:23:54 volumio sudo[23275]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:23:54 volumio volumio[23245]: info: Loading plugin "alsa_controller"...
Sep 13 11:23:54 volumio sudo[23275]: pam_unix(sudo:session): session closed for user root
Sep 13 11:23:54 volumio sudo[23283]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Sep 13 11:23:54 volumio sudo[23283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:23:54 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 13 11:23:54 volumio volumio[23245]: info: Loading plugin "wizard"...
Sep 13 11:23:54 volumio volumio[23245]: info: Loading plugin "networkfs"...
Sep 13 11:23:54 volumio volumio[23245]: info: Starting Udev Watcher for removable devices
Sep 13 11:23:54 volumio volumio[23245]: info: Ignoring mount for partition: boot
Sep 13 11:23:54 volumio volumio[23245]: info: Ignoring mount for partition: volumio
Sep 13 11:23:54 volumio volumio[23245]: info: Ignoring mount for partition: volumio_data
Sep 13 11:23:54 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 13 11:23:54 volumio volumio[23245]: info: Loading plugin "volumio_command_line_client"...
Sep 13 11:23:54 volumio volumio[23245]: info: Loading plugin "upnp"...
Sep 13 11:23:54 volumio volumio[23245]: info: [1757755434368] Starting Upmpd Daemon
Sep 13 11:23:54 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 13 11:23:54 volumio volumio[23245]: info: Loading plugin "my_music"...
Sep 13 11:23:54 volumio volumio[23245]: info: Loading plugin "mpd"...
Sep 13 11:23:54 volumio volumio[23245]: info: Loading plugin "upnp_browser"...
Sep 13 11:23:56 volumio volumio[23245]: info: Loading plugin "alarm-clock"...
Sep 13 11:23:56 volumio volumio[23245]: info: Loading plugin "airplay_emulation"...
Sep 13 11:23:56 volumio volumio[23245]: info: Starting Shairport Sync
Sep 13 11:23:56 volumio volumio[23245]: info: Loading plugin "last_100"...
Sep 13 11:23:56 volumio volumio[23245]: info: Loading plugin "webradio"...
Sep 13 11:23:56 volumio volumio[23245]: info: Loading plugin "i2s_dacs"...
Sep 13 11:23:56 volumio volumio[23245]: info: I2S DAC not set, start Auto-detection
Sep 13 11:23:56 volumio volumio[23245]: info: Loading plugin "volumiodiscovery"...
Sep 13 11:23:56 volumio volumio[23245]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Sep 13 11:23:56 volumio volumio[23245]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 13 11:23:56 volumio volumio[23245]: *** WARNING *** For more information see
Sep 13 11:23:56 volumio volumio[23245]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Sep 13 11:23:56 volumio volumio[23245]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 13 11:23:56 volumio volumio[23245]: *** WARNING *** For more information see
Sep 13 11:23:56 volumio node[23245]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Sep 13 11:23:56 volumio node[23245]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 13 11:23:56 volumio node[23245]: *** WARNING *** For more information see
Sep 13 11:23:56 volumio node[23245]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Sep 13 11:23:56 volumio node[23245]: *** WARNING *** Please fix your application to use the native API of Avahi!
Sep 13 11:23:56 volumio node[23245]: *** WARNING *** For more information see
Sep 13 11:23:56 volumio volumio[23245]: info: Applying required configuration parameters for plugin volumiodiscovery
Sep 13 11:23:56 volumio volumio[23245]: info: Discovery: Started advertising with name: Volumio
Sep 13 11:23:56 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 13 11:23:56 volumio volumio[23245]: info: Loading plugin "soundcloud"...
Sep 13 11:23:57 volumio wpa_supplicant[1003]: RRM: Ignoring radio measurement request: Not RRM network
Sep 13 11:23:57 volumio sudo[23283]: pam_unix(sudo:session): session closed for user root
Sep 13 11:23:57 volumio volumio[23245]: info: Loading plugin "ytmusic"...
Sep 13 11:24:02 volumio volumio[23245]: info: Loading plugin "outputs"...
Sep 13 11:24:02 volumio volumio[23245]: info: Loading plugin "albumart"...
Sep 13 11:24:02 volumio volumio[23245]: info: Plugin example_plugin is not enabled
Sep 13 11:24:02 volumio volumio[23245]: info: Loading plugin "inputs"...
Sep 13 11:24:02 volumio volumio[23245]: info: Loading plugin "updater_comm"...
Sep 13 11:24:02 volumio volumio[23245]: info: Plugin mpdemulation is not enabled
Sep 13 11:24:02 volumio volumio[23245]: info: Loading plugin "rest_api"...
Sep 13 11:24:02 volumio volumio[23245]: info: Loading plugin "websocket"...
Sep 13 11:24:02 volumio volumio[23245]: info: Starting Socket.io Server version 1.7.4
Sep 13 11:24:02 volumio volumio[23245]: info: Loading plugin "touch_display"...
Sep 13 11:24:02 volumio volumio[23245]: info: Applying required configuration parameters for plugin touch_display
Sep 13 11:24:02 volumio volumio[23310]: Forking 3 albumart workers
Sep 13 11:24:02 volumio volumio[23245]: info: Loading i18n strings for locale nl
Sep 13 11:24:02 volumio volumio[23245]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found.
Sep 13 11:24:02 volumio volumio[23245]: Updating browse sources language
Sep 13 11:24:02 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::initPlayerControls
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 13 11:24:03 volumio volumio[23245]: Express server listening on port 3000
Sep 13 11:24:03 volumio volumio[23245]: [Metrics] WebUI: 12s 501.25ms
Sep 13 11:24:03 volumio volumio[23245]: info: CoreStateMachine::resetVolumioState
Sep 13 11:24:03 volumio volumio[23245]: info: CoreStateMachine::getcurrentVolume
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::volumioRetrievevolume
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:24:03 volumio volumio[23245]: info: Volumio Network Manager: Network status updated: 2
Sep 13 11:24:03 volumio volumio[23245]: verbose: New Socket.io Connection to 192.168.0.117 from 192.168.0.239 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:142.0) Gecko/20100101 Firefox/142.0 Engine version: 3 Transport: polling Total Clients: 1
Sep 13 11:24:03 volumio volumio[23245]: info: VolumeController:: Volume=70 Mute =false
Sep 13 11:24:03 volumio volumio[23245]: info: CoreStateMachine::pushState
Sep 13 11:24:03 volumio volumio[23245]: info: CorePlayQueue::getTrack 0
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::volumioPushState
Sep 13 11:24:03 volumio volumio[23245]: info: CoreStateMachine::updateTrackBlock
Sep 13 11:24:03 volumio volumio[23245]: info: CorePlayQueue::getTrackBlock
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::volumioRetrievevolume
Sep 13 11:24:03 volumio volumio[23245]: verbose: New Socket.io Connection to 192.168.0.117 from 192.168.0.239 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:142.0) Gecko/20100101 Firefox/142.0 Engine version: 3 Transport: polling Total Clients: 2
Sep 13 11:24:03 volumio volumio[23245]: info: Reloading queue from file
Sep 13 11:24:03 volumio volumio[23245]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 3
Sep 13 11:24:03 volumio volumio[23245]: info: CoreStateMachine::setRepeat null single undefined
Sep 13 11:24:03 volumio volumio[23245]: info: CoreStateMachine::pushState
Sep 13 11:24:03 volumio volumio[23245]: info: CorePlayQueue::getTrack 0
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::volumioPushState
Sep 13 11:24:03 volumio volumio[23245]: info: CoreStateMachine::setRandom null
Sep 13 11:24:03 volumio volumio[23245]: info: CoreStateMachine::pushState
Sep 13 11:24:03 volumio volumio[23245]: info: CorePlayQueue::getTrack 0
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::volumioPushState
Sep 13 11:24:03 volumio volumio[23245]: info: Setting Device type: Raspberry PI
Sep 13 11:24:03 volumio volumio[23245]: verbose: New Socket.io Connection to 192.168.0.117 from 192.168.0.239 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:142.0) Gecko/20100101 Firefox/142.0 Engine version: 3 Transport: polling Total Clients: 4
Sep 13 11:24:03 volumio volumio[23245]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 5
Sep 13 11:24:03 volumio volumio[23245]: info: VolumeController:: Volume=70 Mute =false
Sep 13 11:24:03 volumio volumio[23245]: info: CoreStateMachine::pushState
Sep 13 11:24:03 volumio volumio[23245]: info: CorePlayQueue::getTrack 0
Sep 13 11:24:03 volumio volumio[23245]: info: CoreCommandRouter::volumioPushState
Sep 13 11:24:04 volumio volumio[23245]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/135.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6
Sep 13 11:24:04 volumio volumio[23245]: verbose: New Socket.io Connection to 192.168.0.117 from 192.168.0.239 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:142.0) Gecko/20100101 Firefox/142.0 Engine version: 3 Transport: polling Total Clients: 7
Sep 13 11:24:04 volumio volumio[23245]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8
Sep 13 11:24:04 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Sep 13 11:24:04 volumio volumio[23245]: info: Discovery: adding dd84ec2b-32f7-452f-b569-f9289558aef1
Sep 13 11:24:04 volumio volumio[23245]: info: Discovery: Found device Volumio
Sep 13 11:24:04 volumio volumio[23245]: info: CoreCommandRouter::volumioGetState
Sep 13 11:24:04 volumio volumio[23245]: info: CorePlayQueue::getTrack 0
Sep 13 11:24:04 volumio volumio[23245]: info: Discovery: this is already registered, dd84ec2b-32f7-452f-b569-f9289558aef1
Sep 13 11:24:04 volumio volumio[23245]: info: Discovery: Found device Volumio
Sep 13 11:24:04 volumio volumio[23245]: info: CoreCommandRouter::volumioGetState
Sep 13 11:24:04 volumio volumio[23245]: info: CorePlayQueue::getTrack 0
Sep 13 11:24:04 volumio volumio[23320]: Starting albumart workers
Sep 13 11:24:04 volumio volumio[23245]: info: Completed loading Core Plugins
Sep 13 11:24:04 volumio volumio[23245]: info: Preparing to generate the ALSA configuration file
Sep 13 11:24:04 volumio sudo[23385]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 13 11:24:04 volumio sudo[23385]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:24:04 volumio sudo[23383]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Sep 13 11:24:04 volumio sudo[23383]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:24:04 volumio sudo[23385]: pam_unix(sudo:session): session closed for user root
Sep 13 11:24:04 volumio sudo[23383]: pam_unix(sudo:session): session closed for user root
Sep 13 11:24:04 volumio volumio[23245]: info: CoreCommandRouter::volumioGetVisibleSources
Sep 13 11:24:04 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 13 11:24:04 volumio volumio[23245]: info: CoreCommandRouter::volumioGetState
Sep 13 11:24:04 volumio volumio[23245]: info: CorePlayQueue::getTrack 0
Sep 13 11:24:04 volumio volumio[23245]: info: CoreCommandRouter::volumioGetState
Sep 13 11:24:04 volumio volumio[23245]: info: CorePlayQueue::getTrack 0
Sep 13 11:24:04 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Sep 13 11:24:04 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Sep 13 11:24:04 volumio volumio[23322]: Starting albumart workers
Sep 13 11:24:04 volumio volumio[23245]: info: Received Get System Info
Sep 13 11:24:04 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 13 11:24:04 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 13 11:24:04 volumio volumio[23245]: info: Discovery: Getting this device information
Sep 13 11:24:04 volumio volumio[23245]: info: CoreCommandRouter::volumioGetState
Sep 13 11:24:04 volumio volumio[23245]: info: CorePlayQueue::getTrack 0
Sep 13 11:24:04 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 13 11:24:04 volumio volumio[23245]: info: CoreCommandRouter::volumioGetState
Sep 13 11:24:04 volumio volumio[23245]: info: CorePlayQueue::getTrack 0
Sep 13 11:24:04 volumio volumio[23321]: Starting albumart workers
Sep 13 11:24:04 volumio volumio[23245]: info: Listing playlists
Sep 13 11:24:05 volumio volumio[23245]: info: Asound.conf file unchanged, so no further update is needed
Sep 13 11:24:05 volumio volumio[23245]: info: Output device has changed, restarting MPD
Sep 13 11:24:05 volumio volumio[23245]: info: Output device has changed, restarting Shairport Sync
Sep 13 11:24:05 volumio sudo[23389]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Sep 13 11:24:05 volumio sudo[23389]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:24:05 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:05 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:24:05 volumio sudo[23392]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Sep 13 11:24:05 volumio sudo[23389]: pam_unix(sudo:session): session closed for user root
Sep 13 11:24:05 volumio sudo[23392]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:24:05 volumio volumio[23245]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Sep 13 11:24:05 volumio volumio[23245]: info: ___________ START PLUGINS ___________
Sep 13 11:24:05 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Sep 13 11:24:05 volumio volumio[23245]: info: ControllerMpd::onStart: Initializing MPD
Sep 13 11:24:05 volumio volumio[23245]: info: Creating MPD Configuration file
Sep 13 11:24:05 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 13 11:24:05 volumio volumio[23245]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 13 11:24:05 volumio volumio[23245]: info: [1757755445549] CoreMusicLibrary::Adding element Media Servers
Sep 13 11:24:05 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 13 11:24:05 volumio sudo[23399]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Sep 13 11:24:05 volumio sudo[23399]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:24:05 volumio sudo[23401]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Sep 13 11:24:05 volumio sudo[23401]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:24:05 volumio sudo[23399]: pam_unix(sudo:session): session closed for user root
Sep 13 11:24:05 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:05 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:24:05 volumio volumio[23245]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Sep 13 11:24:05 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:05 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:24:05 volumio systemd[1]: Starting setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service...
Sep 13 11:24:05 volumio volumio[23245]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Sep 13 11:24:05 volumio volumio[23245]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 13 11:24:05 volumio volumio[23245]: info: [1757755445881] CoreMusicLibrary::Adding element Last_100
Sep 13 11:24:05 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 13 11:24:05 volumio volumio[23245]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 13 11:24:05 volumio volumio[23245]: info: [1757755445887] CoreMusicLibrary::Adding element Webradio
Sep 13 11:24:05 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 13 11:24:05 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 13 11:24:05 volumio volumio[23245]: info: Initializing BBC Radios
Sep 13 11:24:05 volumio volumio-remote-updater[585]: [2025-09-13 11:24:05] [connect] Successful connection
Sep 13 11:24:06 volumio dbus-daemon[564]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.183' (uid=0 pid=23413 comm="timedatectl show --property=NTPSynchronized --valu")
Sep 13 11:24:06 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 13 11:24:06 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:24:06 volumio volumio[23245]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 13 11:24:06 volumio volumio[23245]: info: [1757755446059] CoreMusicLibrary::Adding element SoundCloud
Sep 13 11:24:06 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 13 11:24:06 volumio volumio[23245]: Cannot find translation for source SoundCloud
Sep 13 11:24:06 volumio volumio[23245]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Sep 13 11:24:06 volumio volumio[23245]: info: [1757755446079] CoreMusicLibrary::Adding element YouTube Music
Sep 13 11:24:06 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 13 11:24:06 volumio volumio[23245]: Cannot find translation for source SoundCloud
Sep 13 11:24:06 volumio volumio[23245]: Cannot find translation for source YouTube Music
Sep 13 11:24:06 volumio volumio[23245]: info: Loading i18n strings for locale nl
Sep 13 11:24:06 volumio volumio[23245]: error: touch_display: Fetching language file: Error: i18n file complementing the system language not found.
Sep 13 11:24:06 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Sep 13 11:24:06 volumio volumio[23245]: info: Volumio Calling Home
Sep 13 11:24:06 volumio systemd[1]: Starting systemd-timedated.service - Time & Date Service...
Sep 13 11:24:06 volumio sudo[23441]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl disable getty@tty1.service
Sep 13 11:24:06 volumio sudo[23443]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl daemon-reload
Sep 13 11:24:06 volumio sudo[23443]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:24:06 volumio sudo[23438]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop getty@tty1.service
Sep 13 11:24:06 volumio sudo[23438]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:24:06 volumio sudo[23441]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:24:06 volumio systemd[1]: Reloading.
Sep 13 11:24:06 volumio dbus-daemon[564]: [system] Successfully activated service 'org.freedesktop.timedate1'
Sep 13 11:24:06 volumio setdatetime-helper.sh[23405]: Time is already synchronized.
Sep 13 11:24:07 volumio volumio[23245]: info: touch_display: No backlight interface detected.
Sep 13 11:24:07 volumio volumio[23245]: verbose: New Socket.io Connection to 192.168.0.117 from 192.168.0.239 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:142.0) Gecko/20100101 Firefox/142.0 Engine version: 3 Transport: polling Total Clients: 9
Sep 13 11:24:07 volumio volumio[23245]: info: MPD Permissions set
Sep 13 11:24:07 volumio volumio[23245]: info: MPD Permissions set
Sep 13 11:24:07 volumio sudo[23476]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Sep 13 11:24:07 volumio sudo[23476]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:24:07 volumio volumio-remote-updater[585]: [2025-09-13 11:24:07] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1757755445 101
Sep 13 11:24:07 volumio volumio[23245]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 3 Transport: websocket Total Clients: 10
Sep 13 11:24:07 volumio volumio[23245]: info: Volumio called home
Sep 13 11:24:07 volumio volumio[23245]: Searching plugin music_service/webradio
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: webradio , search
Sep 13 11:24:07 volumio volumio[23245]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 11
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::volumioGetVisibleSources
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::volumioGetState
Sep 13 11:24:07 volumio volumio[23245]: info: CorePlayQueue::getTrack 0
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::volumioGetState
Sep 13 11:24:07 volumio volumio[23245]: info: CorePlayQueue::getTrack 0
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::volumioGetQueue
Sep 13 11:24:07 volumio volumio[23245]: info: CoreStateMachine::getQueue
Sep 13 11:24:07 volumio volumio[23245]: info: CorePlayQueue::getQueue
Sep 13 11:24:07 volumio volumio[23245]: info: Listing playlists
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Sep 13 11:24:07 volumio volumio[23245]: info: Received Get System Info
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Sep 13 11:24:07 volumio volumio[23245]: info: Discovery: Getting this device information
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::volumioGetState
Sep 13 11:24:07 volumio volumio[23245]: info: CorePlayQueue::getTrack 0
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Sep 13 11:24:07 volumio volumio[23245]: info: CoreCommandRouter::volumioGetState
Sep 13 11:24:07 volumio volumio[23245]: info: CorePlayQueue::getTrack 0
Sep 13 11:24:07 volumio volumio[23245]: info: touch_display: No Raspberry Pi Foundation touch screen detected.
Sep 13 11:24:07 volumio sudo[23489]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/99-vc4.conf
Sep 13 11:24:07 volumio sudo[23489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:24:07 volumio sudo[23489]: pam_unix(sudo:session): session closed for user root
Sep 13 11:24:07 volumio sudo[23491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf
Sep 13 11:24:07 volumio sudo[23491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:24:07 volumio sudo[23491]: pam_unix(sudo:session): session closed for user root
Sep 13 11:24:07 volumio volumio[23245]: info: Starting Shairport Sync
Sep 13 11:24:07 volumio volumio[23245]: info: Starting Shairport Sync
Sep 13 11:24:07 volumio volumio[23245]: info: Starting Shairport Sync
Sep 13 11:24:07 volumio sudo[23498]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Sep 13 11:24:07 volumio sudo[23498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:24:07 volumio sudo[23500]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Sep 13 11:24:07 volumio sudo[23500]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:24:07 volumio sudo[23502]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Sep 13 11:24:07 volumio sudo[23502]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Sep 13 11:24:07 volumio volumio[23245]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set.
Sep 13 11:24:07 volumio volumio[23245]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/99-vc4.conf set.
Sep 13 11:24:08 volumio volumio[23245]: Use XMLElement.setAttribute instead
Sep 13 11:24:08 volumio volumio[23245]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 13 11:24:08 volumio volumio[23245]: TypeError: children[i].attr(...).value is not a function
Sep 13 11:24:08 volumio volumio[23245]: at /volumio/app/plugins/music_service/webradio/index.js:956:46
Sep 13 11:24:08 volumio volumio[23245]: at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
Sep 13 11:24:08 volumio volumio[23245]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 13 11:24:08 volumio systemd[1]: mpd.service: Deactivated successfully.
Sep 13 11:24:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Sep 13 11:24:08 volumio sudo[23443]: pam_unix(sudo:session): session closed for user root
Sep 13 11:24:08 volumio systemd[1]: mpd.service: Consumed 6.845s CPU time.
Sep 13 11:24:08 volumio systemd[1]: setdatetime-helper.timer.service: Deactivated successfully.
Sep 13 11:24:08 volumio systemd[1]: Finished setdatetime-helper.timer.service - Volumio Time Sync Watchdog Service.
Sep 13 11:24:08 volumio systemd[1]: Reloading.
Sep 13 11:24:09 volumio sudo[23521]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-09-13 11:23'
Sep 13 11:24:09 volumio sudo[23521]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
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="1da895bfdbb6eb90d965df32a25a3568df7c84ed"
VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6"
VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a"
VOLUMIO_BE_VERSION="04c18c158cc4bac70764c3360b25fcce0c69266a"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu May 29 13:12:59 UTC 2025"
VOLUMIO_VERSION="4.004"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="2df63d74196e499fa1e34fb765df1cca"