-- Logs begin at Thu 2025-07-03 14:25:48 UTC, end at Thu 2025-07-03 14:29:25 UTC. -- Jul 03 14:28:00 volumio volumio-remote-updater[615]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:00 volumio volumio-remote-updater[615]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:00 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:00 volumio volumio[999]: updateProgress Jul 03 14:28:00 volumio volumio[999]: { Jul 03 14:28:00 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:00 volumio volumio[999]: eta: '5m', Jul 03 14:28:00 volumio volumio[999]: progress: 13, Jul 03 14:28:00 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:00 volumio volumio[999]: } Jul 03 14:28:00 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:00 volumio volumio[999]: updateProgress Jul 03 14:28:00 volumio volumio[999]: { Jul 03 14:28:00 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:00 volumio volumio[999]: eta: '5m', Jul 03 14:28:00 volumio volumio[999]: progress: 13, Jul 03 14:28:00 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:00 volumio volumio[999]: } Jul 03 14:28:02 volumio volumio[999]: info: CoreCommandRouter::servicePushState Jul 03 14:28:02 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:02 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 03 14:28:02 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:02 volumio volumio[999]: info: CoreCommandRouter::servicePushState Jul 03 14:28:02 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:02 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:02 volumio volumio[999]: info: CoreCommandRouter::servicePushState Jul 03 14:28:02 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:02 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:02 volumio shairport-sync[1306]: {"time":1751552828489,"response":"startAirplayPlayback Success"} % Total % Received % Xferd Average Speed Time Time Time Current Jul 03 14:28:02 volumio shairport-sync[1306]: Dload Upload Total Spent Left Speed Jul 03 14:28:02 volumio volumio[999]: info: Jul 03 14:28:02 volumio volumio[999]: ---------------------------- Client requests Stop Airplay Playback Jul 03 14:28:02 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , stopAirplayPlayback Jul 03 14:28:02 volumio volumio[999]: info: Airplay playback stop Jul 03 14:28:02 volumio volumio[999]: info: Airplay Playback Stopped, clearing state Jul 03 14:28:02 volumio volumio[999]: info: CoreStateMachine::resetVolumioState Jul 03 14:28:02 volumio volumio[999]: info: CoreStateMachine::getcurrentVolume Jul 03 14:28:02 volumio volumio[999]: info: CoreCommandRouter::volumioRetrievevolume Jul 03 14:28:02 volumio shairport-sync[1306]: [158B blob data] Jul 03 14:28:02 volumio volumio[999]: info: VolumeController:: Volume=100 Mute =false Jul 03 14:28:02 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:02 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 03 14:28:02 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:02 volumio volumio[999]: info: CoreStateMachine::updateTrackBlock Jul 03 14:28:02 volumio volumio[999]: info: CorePlayQueue::getTrackBlock Jul 03 14:28:02 volumio volumio[999]: info: CoreCommandRouter::volumioRetrievevolume Jul 03 14:28:02 volumio volumio[999]: info: Airplay started streaming, receiving metadatas Jul 03 14:28:02 volumio volumio[999]: info: Airplay started streaming, receiving metadatas Jul 03 14:28:02 volumio volumio[999]: info: Airplay started streaming, receiving metadatas Jul 03 14:28:02 volumio volumio[999]: info: VolumeController:: Volume=100 Mute =false Jul 03 14:28:02 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:02 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 03 14:28:02 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:02 volumio shairport-sync[1306]: {"time":1751552882506,"response":"stopAirplayPlayback Success"} % Total % Received % Xferd Average Speed Time Time Time Current Jul 03 14:28:02 volumio shairport-sync[1306]: Dload Upload Total Spent Left Speed Jul 03 14:28:02 volumio volumio[999]: info: Jul 03 14:28:02 volumio volumio[999]: ---------------------------- Client requests Start Airplay PlaybackRoutine Jul 03 14:28:02 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback Jul 03 14:28:02 volumio volumio[999]: info: Airplay playback start Jul 03 14:28:02 volumio shairport-sync[1306]: [158B blob data] Jul 03 14:28:03 volumio volumio-remote-updater[615]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:03 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:03 volumio volumio[999]: updateProgress Jul 03 14:28:03 volumio volumio[999]: { Jul 03 14:28:03 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:03 volumio volumio[999]: eta: '5m', Jul 03 14:28:03 volumio volumio[999]: progress: 13, Jul 03 14:28:03 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:03 volumio volumio[999]: } Jul 03 14:28:03 volumio volumio[999]: info: CoreCommandRouter::servicePushState Jul 03 14:28:03 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:03 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 03 14:28:03 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:03 volumio volumio[999]: info: CoreCommandRouter::servicePushState Jul 03 14:28:03 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:03 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:03 volumio volumio[999]: info: CoreCommandRouter::servicePushState Jul 03 14:28:03 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:03 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:03 volumio volumio[999]: info: CoreCommandRouter::servicePushState Jul 03 14:28:03 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:03 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:04 volumio volumio-remote-updater[615]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:04 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:04 volumio volumio[999]: updateProgress Jul 03 14:28:04 volumio volumio[999]: { Jul 03 14:28:04 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:04 volumio volumio[999]: eta: '5m', Jul 03 14:28:04 volumio volumio[999]: progress: 13, Jul 03 14:28:04 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:04 volumio volumio[999]: } Jul 03 14:28:04 volumio volumio[999]: info: CoreCommandRouter::servicePushState Jul 03 14:28:04 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:04 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 03 14:28:04 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:04 volumio volumio[999]: info: CoreCommandRouter::servicePushState Jul 03 14:28:04 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:04 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:04 volumio volumio[999]: info: CoreCommandRouter::servicePushState Jul 03 14:28:04 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:04 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:04 volumio volumio[999]: info: CoreCommandRouter::servicePushState Jul 03 14:28:04 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:04 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jul 03 14:28:04 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:04 volumio volumio[999]: info: CoreCommandRouter::servicePushState Jul 03 14:28:04 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:04 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:04 volumio volumio[999]: info: CoreCommandRouter::servicePushState Jul 03 14:28:04 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:04 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:05 volumio volumio-remote-updater[615]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:05 volumio volumio-remote-updater[615]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:05 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:05 volumio volumio[999]: updateProgress Jul 03 14:28:05 volumio volumio[999]: { Jul 03 14:28:05 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:05 volumio volumio[999]: eta: '5m', Jul 03 14:28:05 volumio volumio[999]: progress: 13, Jul 03 14:28:05 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:05 volumio volumio[999]: } Jul 03 14:28:07 volumio volumio-remote-updater[615]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:07 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:07 volumio volumio[999]: updateProgress Jul 03 14:28:07 volumio volumio[999]: { Jul 03 14:28:07 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:07 volumio volumio[999]: eta: '5m', Jul 03 14:28:07 volumio volumio[999]: progress: 13, Jul 03 14:28:07 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:07 volumio volumio[999]: } Jul 03 14:28:08 volumio volumio-remote-updater[615]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:08 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:08 volumio volumio[999]: updateProgress Jul 03 14:28:08 volumio volumio[999]: { Jul 03 14:28:08 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:08 volumio volumio[999]: eta: '5m', Jul 03 14:28:08 volumio volumio[999]: progress: 13, Jul 03 14:28:08 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:08 volumio volumio[999]: } Jul 03 14:28:09 volumio volumio-remote-updater[615]: PROGRESS: 13, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:09 volumio volumio-remote-updater[615]: PROGRESS: 14, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:09 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:09 volumio volumio[999]: updateProgress Jul 03 14:28:09 volumio volumio[999]: { Jul 03 14:28:09 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:09 volumio volumio[999]: eta: '5m', Jul 03 14:28:09 volumio volumio[999]: progress: 14, Jul 03 14:28:09 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:09 volumio volumio[999]: } Jul 03 14:28:10 volumio volumio-remote-updater[615]: PROGRESS: 14, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:10 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:10 volumio volumio[999]: updateProgress Jul 03 14:28:10 volumio volumio[999]: { Jul 03 14:28:10 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:10 volumio volumio[999]: eta: '5m', Jul 03 14:28:10 volumio volumio[999]: progress: 14, Jul 03 14:28:10 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:10 volumio volumio[999]: } Jul 03 14:28:11 volumio volumio-remote-updater[615]: PROGRESS: 14, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:11 volumio volumio-remote-updater[615]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:11 volumio volumio-remote-updater[615]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:11 volumio volumio-remote-updater[615]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:11 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:11 volumio volumio[999]: updateProgress Jul 03 14:28:11 volumio volumio[999]: { Jul 03 14:28:11 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:11 volumio volumio[999]: eta: '5m', Jul 03 14:28:11 volumio volumio[999]: progress: 15, Jul 03 14:28:11 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:11 volumio volumio[999]: } Jul 03 14:28:11 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:11 volumio volumio[999]: updateProgress Jul 03 14:28:11 volumio volumio[999]: { Jul 03 14:28:11 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:11 volumio volumio[999]: eta: '5m', Jul 03 14:28:11 volumio volumio[999]: progress: 15, Jul 03 14:28:11 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:11 volumio volumio[999]: } Jul 03 14:28:12 volumio volumio-remote-updater[615]: PROGRESS: 15, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:12 volumio volumio-remote-updater[615]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:12 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:12 volumio volumio[999]: updateProgress Jul 03 14:28:12 volumio volumio[999]: { Jul 03 14:28:12 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:12 volumio volumio[999]: eta: '5m', Jul 03 14:28:12 volumio volumio[999]: progress: 16, Jul 03 14:28:12 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:12 volumio volumio[999]: } Jul 03 14:28:12 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:12 volumio volumio[999]: updateProgress Jul 03 14:28:12 volumio volumio[999]: { Jul 03 14:28:12 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:12 volumio volumio[999]: eta: '5m', Jul 03 14:28:12 volumio volumio[999]: progress: 16, Jul 03 14:28:12 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:12 volumio volumio[999]: } Jul 03 14:28:13 volumio volumio-remote-updater[615]: PROGRESS: 16, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:13 volumio volumio-remote-updater[615]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:13 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:13 volumio volumio[999]: updateProgress Jul 03 14:28:13 volumio volumio[999]: { Jul 03 14:28:13 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:13 volumio volumio[999]: eta: '5m', Jul 03 14:28:13 volumio volumio[999]: progress: 17, Jul 03 14:28:13 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:13 volumio volumio[999]: } Jul 03 14:28:13 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:13 volumio volumio[999]: updateProgress Jul 03 14:28:13 volumio volumio[999]: { Jul 03 14:28:13 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:13 volumio volumio[999]: eta: '5m', Jul 03 14:28:13 volumio volumio[999]: progress: 17, Jul 03 14:28:13 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:13 volumio volumio[999]: } Jul 03 14:28:14 volumio volumio-remote-updater[615]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:14 volumio volumio-remote-updater[615]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:14 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:14 volumio volumio[999]: updateProgress Jul 03 14:28:14 volumio volumio[999]: { Jul 03 14:28:14 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:14 volumio volumio[999]: eta: '5m', Jul 03 14:28:14 volumio volumio[999]: progress: 17, Jul 03 14:28:14 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:14 volumio volumio[999]: } Jul 03 14:28:15 volumio volumio-remote-updater[615]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:15 volumio volumio-remote-updater[615]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:15 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:15 volumio volumio[999]: updateProgress Jul 03 14:28:15 volumio volumio[999]: { Jul 03 14:28:15 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:15 volumio volumio[999]: eta: '5m', Jul 03 14:28:15 volumio volumio[999]: progress: 17, Jul 03 14:28:15 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:15 volumio volumio[999]: } Jul 03 14:28:15 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:15 volumio volumio[999]: updateProgress Jul 03 14:28:15 volumio volumio[999]: { Jul 03 14:28:15 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:15 volumio volumio[999]: eta: '5m', Jul 03 14:28:15 volumio volumio[999]: progress: 17, Jul 03 14:28:15 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:15 volumio volumio[999]: } Jul 03 14:28:16 volumio volumio-remote-updater[615]: PROGRESS: 17, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:16 volumio volumio-remote-updater[615]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:16 volumio volumio-remote-updater[615]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:16 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:16 volumio volumio[999]: updateProgress Jul 03 14:28:16 volumio volumio[999]: { Jul 03 14:28:16 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:16 volumio volumio[999]: eta: '5m', Jul 03 14:28:16 volumio volumio[999]: progress: 18, Jul 03 14:28:16 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:16 volumio volumio[999]: } Jul 03 14:28:16 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:16 volumio volumio[999]: updateProgress Jul 03 14:28:16 volumio volumio[999]: { Jul 03 14:28:16 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:16 volumio volumio[999]: eta: '5m', Jul 03 14:28:16 volumio volumio[999]: progress: 18, Jul 03 14:28:16 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:16 volumio volumio[999]: } Jul 03 14:28:17 volumio volumio-remote-updater[615]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:17 volumio volumio-remote-updater[615]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:17 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:17 volumio volumio[999]: updateProgress Jul 03 14:28:17 volumio volumio[999]: { Jul 03 14:28:17 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:17 volumio volumio[999]: eta: '5m', Jul 03 14:28:17 volumio volumio[999]: progress: 18, Jul 03 14:28:17 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:17 volumio volumio[999]: } Jul 03 14:28:18 volumio volumio-remote-updater[615]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:18 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:18 volumio volumio[999]: updateProgress Jul 03 14:28:18 volumio volumio[999]: { Jul 03 14:28:18 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:18 volumio volumio[999]: eta: '5m', Jul 03 14:28:18 volumio volumio[999]: progress: 18, Jul 03 14:28:18 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:18 volumio volumio[999]: } Jul 03 14:28:19 volumio volumio-remote-updater[615]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:19 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:19 volumio volumio[999]: updateProgress Jul 03 14:28:19 volumio volumio[999]: { Jul 03 14:28:19 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:19 volumio volumio[999]: eta: '5m', Jul 03 14:28:19 volumio volumio[999]: progress: 18, Jul 03 14:28:19 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:19 volumio volumio[999]: } Jul 03 14:28:20 volumio volumio-remote-updater[615]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:20 volumio volumio-remote-updater[615]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:20 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:20 volumio volumio[999]: updateProgress Jul 03 14:28:20 volumio volumio[999]: { Jul 03 14:28:20 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:20 volumio volumio[999]: eta: '5m', Jul 03 14:28:20 volumio volumio[999]: progress: 18, Jul 03 14:28:20 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:20 volumio volumio[999]: } Jul 03 14:28:21 volumio volumio-remote-updater[615]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:21 volumio volumio-remote-updater[615]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:21 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:21 volumio volumio[999]: updateProgress Jul 03 14:28:21 volumio volumio[999]: { Jul 03 14:28:21 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:21 volumio volumio[999]: eta: '5m', Jul 03 14:28:21 volumio volumio[999]: progress: 18, Jul 03 14:28:21 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:21 volumio volumio[999]: } Jul 03 14:28:22 volumio volumio-remote-updater[615]: PROGRESS: 18, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:22 volumio volumio-remote-updater[615]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:22 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:22 volumio volumio[999]: updateProgress Jul 03 14:28:22 volumio volumio[999]: { Jul 03 14:28:22 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:22 volumio volumio[999]: eta: '5m', Jul 03 14:28:22 volumio volumio[999]: progress: 19, Jul 03 14:28:22 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:22 volumio volumio[999]: } Jul 03 14:28:23 volumio volumio-remote-updater[615]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:23 volumio volumio-remote-updater[615]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:23 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:23 volumio volumio[999]: updateProgress Jul 03 14:28:23 volumio volumio[999]: { Jul 03 14:28:23 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:23 volumio volumio[999]: eta: '5m', Jul 03 14:28:23 volumio volumio[999]: progress: 19, Jul 03 14:28:23 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:23 volumio volumio[999]: } Jul 03 14:28:25 volumio volumio-remote-updater[615]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:25 volumio volumio-remote-updater[615]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:25 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:25 volumio volumio[999]: updateProgress Jul 03 14:28:25 volumio volumio[999]: { Jul 03 14:28:25 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:25 volumio volumio[999]: eta: '5m', Jul 03 14:28:25 volumio volumio[999]: progress: 19, Jul 03 14:28:25 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:25 volumio volumio[999]: } Jul 03 14:28:26 volumio volumio-remote-updater[615]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:26 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:26 volumio volumio[999]: updateProgress Jul 03 14:28:26 volumio volumio[999]: { Jul 03 14:28:26 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:26 volumio volumio[999]: eta: '5m', Jul 03 14:28:26 volumio volumio[999]: progress: 19, Jul 03 14:28:26 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:26 volumio volumio[999]: } Jul 03 14:28:26 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:26 volumio volumio[999]: updateProgress Jul 03 14:28:26 volumio volumio[999]: { Jul 03 14:28:26 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:26 volumio volumio[999]: eta: '5m', Jul 03 14:28:26 volumio volumio[999]: progress: 19, Jul 03 14:28:26 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:26 volumio volumio[999]: } Jul 03 14:28:27 volumio volumio-remote-updater[615]: PROGRESS: 19, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:27 volumio volumio-remote-updater[615]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:27 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:27 volumio volumio[999]: updateProgress Jul 03 14:28:27 volumio volumio[999]: { Jul 03 14:28:27 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:27 volumio volumio[999]: eta: '5m', Jul 03 14:28:27 volumio volumio[999]: progress: 20, Jul 03 14:28:27 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:27 volumio volumio[999]: } Jul 03 14:28:28 volumio volumio-remote-updater[615]: PROGRESS: 20, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:28 volumio volumio-remote-updater[615]: PROGRESS: 21, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:28 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:28 volumio volumio[999]: updateProgress Jul 03 14:28:28 volumio volumio[999]: { Jul 03 14:28:28 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:28 volumio volumio[999]: eta: '5m', Jul 03 14:28:28 volumio volumio[999]: progress: 21, Jul 03 14:28:28 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:28 volumio volumio[999]: } Jul 03 14:28:28 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:28 volumio volumio[999]: updateProgress Jul 03 14:28:28 volumio volumio[999]: { Jul 03 14:28:28 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:28 volumio volumio[999]: eta: '5m', Jul 03 14:28:28 volumio volumio[999]: progress: 21, Jul 03 14:28:28 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:28 volumio volumio[999]: } Jul 03 14:28:29 volumio volumio-remote-updater[615]: PROGRESS: 21, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:29 volumio volumio-remote-updater[615]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:29 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:29 volumio volumio[999]: updateProgress Jul 03 14:28:29 volumio volumio[999]: { Jul 03 14:28:29 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:29 volumio volumio[999]: eta: '5m', Jul 03 14:28:29 volumio volumio[999]: progress: 22, Jul 03 14:28:29 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:29 volumio volumio[999]: } Jul 03 14:28:29 volumio kernel: usb 1-1.3.2: USB disconnect, device number 5 Jul 03 14:28:29 volumio thd[626]: Error reading device '/dev/input/event3' Jul 03 14:28:29 volumio volumio[999]: info: No valid Plugin REST Endpoint Jul 03 14:28:29 volumio volumio[999]: info: Jul 03 14:28:29 volumio volumio[999]: ---------------------------- USB Audio Device Detached Jul 03 14:28:29 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach Jul 03 14:28:29 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 03 14:28:29 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: raat , onStop Jul 03 14:28:30 volumio volumio-remote-updater[615]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:30 volumio volumio-remote-updater[615]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:30 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:30 volumio volumio[999]: updateProgress Jul 03 14:28:30 volumio volumio[999]: { Jul 03 14:28:30 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:30 volumio volumio[999]: eta: '5m', Jul 03 14:28:30 volumio volumio[999]: progress: 22, Jul 03 14:28:30 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:30 volumio volumio[999]: } Jul 03 14:28:31 volumio volumio-remote-updater[615]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:31 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:31 volumio volumio[999]: updateProgress Jul 03 14:28:31 volumio volumio[999]: { Jul 03 14:28:31 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:31 volumio volumio[999]: eta: '5m', Jul 03 14:28:31 volumio volumio[999]: progress: 22, Jul 03 14:28:31 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:31 volumio volumio[999]: } Jul 03 14:28:31 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:31 volumio volumio[999]: updateProgress Jul 03 14:28:31 volumio volumio[999]: { Jul 03 14:28:31 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:31 volumio volumio[999]: eta: '5m', Jul 03 14:28:31 volumio volumio[999]: progress: 22, Jul 03 14:28:31 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:31 volumio volumio[999]: } Jul 03 14:28:32 volumio volumio-remote-updater[615]: PROGRESS: 22, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:32 volumio volumio-remote-updater[615]: PROGRESS: 23, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:32 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:32 volumio volumio[999]: updateProgress Jul 03 14:28:32 volumio volumio[999]: { Jul 03 14:28:32 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:32 volumio volumio[999]: eta: '5m', Jul 03 14:28:32 volumio volumio[999]: progress: 23, Jul 03 14:28:32 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:32 volumio volumio[999]: } Jul 03 14:28:33 volumio volumio-remote-updater[615]: PROGRESS: 23, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:33 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:33 volumio volumio[999]: updateProgress Jul 03 14:28:33 volumio volumio[999]: { Jul 03 14:28:33 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:33 volumio volumio[999]: eta: '5m', Jul 03 14:28:33 volumio volumio[999]: progress: 23, Jul 03 14:28:33 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:33 volumio volumio[999]: } Jul 03 14:28:33 volumio kernel: usb 1-1.3.2: new full-speed USB device number 6 using ehci-pci Jul 03 14:28:34 volumio kernel: usb 1-1.3.2: New USB device found, idVendor=0d8c, idProduct=0102, bcdDevice= 0.10 Jul 03 14:28:34 volumio kernel: usb 1-1.3.2: New USB device strings: Mfr=0, Product=2, SerialNumber=0 Jul 03 14:28:34 volumio kernel: usb 1-1.3.2: Product: USB Sound Device Jul 03 14:28:34 volumio kernel: usb 1-1.3.2: current rate 30464 is different from the runtime rate 96000 Jul 03 14:28:34 volumio kernel: usb 1-1.3.2: Warning! Unlikely big volume range (=8065), cval->res is probably wrong. Jul 03 14:28:34 volumio kernel: usb 1-1.3.2: [9] FU [Mic Playback Volume] ch = 2, val = -6144/1921/1 Jul 03 14:28:34 volumio kernel: usb 1-1.3.2: Warning! Unlikely big volume range (=8065), cval->res is probably wrong. Jul 03 14:28:34 volumio kernel: usb 1-1.3.2: [11] FU [Line Playback Volume] ch = 2, val = -6144/1921/1 Jul 03 14:28:34 volumio kernel: usb 1-1.3.2: Warning! Unlikely big volume range (=6928), cval->res is probably wrong. Jul 03 14:28:34 volumio kernel: usb 1-1.3.2: [8] FU [Mic Capture Volume] ch = 2, val = -4096/2832/1 Jul 03 14:28:34 volumio kernel: usb 1-1.3.2: Warning! Unlikely big volume range (=6928), cval->res is probably wrong. Jul 03 14:28:34 volumio kernel: usb 1-1.3.2: [15] FU [Line Capture Volume] ch = 2, val = -4096/2832/1 Jul 03 14:28:34 volumio kernel: usb 1-1.3.2: Warning! Unlikely big volume range (=6928), cval->res is probably wrong. Jul 03 14:28:34 volumio kernel: usb 1-1.3.2: [2] FU [PCM Capture Volume] ch = 2, val = -4096/2832/1 Jul 03 14:28:34 volumio kernel: input: USB Sound Device as /devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.3/1-1.3.2/1-1.3.2:1.3/0003:0D8C:0102.0002/input/input10 Jul 03 14:28:34 volumio kernel: hid-generic 0003:0D8C:0102.0002: input,hidraw0: USB HID v1.00 Device [USB Sound Device ] on usb-0000:00:1d.0-1.3.2/input3 Jul 03 14:28:34 volumio volumio[999]: info: No valid Plugin REST Endpoint Jul 03 14:28:34 volumio volumio[999]: info: Jul 03 14:28:34 volumio volumio[999]: ---------------------------- USB Audio Device Attached Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::Close All Modals sent Jul 03 14:28:34 volumio volumio[999]: info: Preparing to save Alsa Options, stopping services first Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::volumioGetState Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::volumioPause Jul 03 14:28:34 volumio volumio[999]: info: CoreStateMachine::pause Jul 03 14:28:34 volumio volumio[999]: info: CoreStateMachine::stPlaybackTimer Jul 03 14:28:34 volumio volumio[999]: info: CoreStateMachine::servicePause Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::servicePause Jul 03 14:28:34 volumio volumio[999]: info: Airplay Pause with DBUS Call Jul 03 14:28:34 volumio systemd-udevd[1833]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jul 03 14:28:34 volumio volumio[999]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"ICUSBAUDIO7D","alsacard":"ICUSBAUDIO7D"},"i2s":false} Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 03 14:28:34 volumio volumio[999]: info: Setting mixer Speaker for card ICUSBAUDIO7D Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jul 03 14:28:34 volumio volumio[999]: info: Updating Volume Controller Parameters: Device: 5 Name: ICUSBAUDIO7D Mixer: Speaker Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jul 03 14:28:34 volumio volumio[999]: info: Disabling external Volume Control Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 14:28:34 volumio volumio[999]: info: Preparing to generate the ALSA configuration file Jul 03 14:28:34 volumio volumio[999]: info: Error Airplay DBUS Call Pause: Error: Command failed: /usr/bin/dbus-send --system --print-reply --type=method_call --dest=org.gnome.ShairportSync '/org/gnome/ShairportSync' org.gnome.ShairportSync.RemoteControl.Pause Jul 03 14:28:34 volumio volumio[999]: Error org.freedesktop.DBus.Error.ServiceUnknown: The name org.gnome.ShairportSync was not provided by any .service files Jul 03 14:28:34 volumio volumio-remote-updater[615]: PROGRESS: 23, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:34 volumio volumio[999]: info: Asound.conf file unchanged, so no further update is needed Jul 03 14:28:34 volumio volumio[999]: info: Output device has changed, restarting MPD Jul 03 14:28:34 volumio volumio[999]: info: Output device has changed, restarting Shairport Sync Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 14:28:34 volumio volumio[999]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 03 14:28:34 volumio sudo[1859]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 03 14:28:34 volumio sudo[1857]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 03 14:28:34 volumio sudo[1857]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 14:28:34 volumio sudo[1859]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 14:28:34 volumio sudo[1857]: pam_unix(sudo:session): session closed for user root Jul 03 14:28:34 volumio systemd[1]: Stopping Music Player Daemon... Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 03 14:28:34 volumio volumio[999]: info: MPD Permissions set Jul 03 14:28:34 volumio volumio[999]: info: VolumeController:: Volume=100 Mute =false Jul 03 14:28:34 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:34 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:34 volumio systemd[1]: mpd.service: Succeeded. Jul 03 14:28:34 volumio systemd[1]: Stopped Music Player Daemon. Jul 03 14:28:34 volumio volumio[999]: updateProgress Jul 03 14:28:34 volumio volumio[999]: { Jul 03 14:28:34 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:34 volumio volumio[999]: eta: '5m', Jul 03 14:28:34 volumio volumio[999]: progress: 23, Jul 03 14:28:34 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:34 volumio volumio[999]: } Jul 03 14:28:34 volumio volumio[999]: info: Starting Shairport Sync Jul 03 14:28:34 volumio systemd[1]: Starting Music Player Daemon... Jul 03 14:28:34 volumio sudo[1877]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 03 14:28:34 volumio sudo[1877]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 14:28:34 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 03 14:28:34 volumio shairport-sync[1306]: {"time":1751552882648,"response":"startAirplayPlayback Success"} Jul 03 14:28:34 volumio systemd[1]: shairport-sync.service: Succeeded. Jul 03 14:28:34 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jul 03 14:28:34 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 03 14:28:34 volumio sudo[1877]: pam_unix(sudo:session): session closed for user root Jul 03 14:28:34 volumio volumio[999]: info: Shairport-Sync Started Jul 03 14:28:34 volumio sudo[1875]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 03 14:28:34 volumio sudo[1875]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 14:28:34 volumio sudo[1875]: pam_unix(sudo:session): session closed for user root Jul 03 14:28:35 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat Jul 03 14:28:35 volumio kernel: usb 1-1.3.2: USB disconnect, device number 6 Jul 03 14:28:35 volumio volumio-remote-updater[615]: PROGRESS: 23, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:35 volumio volumio[999]: info: No valid Plugin REST Endpoint Jul 03 14:28:35 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:35 volumio volumio[999]: updateProgress Jul 03 14:28:35 volumio volumio[999]: { Jul 03 14:28:35 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:35 volumio volumio[999]: eta: '5m', Jul 03 14:28:35 volumio volumio[999]: progress: 23, Jul 03 14:28:35 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:35 volumio volumio[999]: } Jul 03 14:28:35 volumio volumio[999]: info: Jul 03 14:28:35 volumio volumio[999]: ---------------------------- USB Audio Device Detached Jul 03 14:28:35 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach Jul 03 14:28:35 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 03 14:28:35 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: raat , onStop Jul 03 14:28:35 volumio kernel: usb 1-1.3.2: new full-speed USB device number 7 using ehci-pci Jul 03 14:28:35 volumio kernel: usb 1-1.3.2: New USB device found, idVendor=0d8c, idProduct=0102, bcdDevice= 0.10 Jul 03 14:28:35 volumio kernel: usb 1-1.3.2: New USB device strings: Mfr=0, Product=2, SerialNumber=0 Jul 03 14:28:35 volumio kernel: usb 1-1.3.2: Product: USB Sound Device Jul 03 14:28:35 volumio kernel: usb 1-1.3.2: current rate 30464 is different from the runtime rate 96000 Jul 03 14:28:35 volumio kernel: usb 1-1.3.2: Warning! Unlikely big volume range (=8065), cval->res is probably wrong. Jul 03 14:28:35 volumio kernel: usb 1-1.3.2: [9] FU [Mic Playback Volume] ch = 2, val = -6144/1921/1 Jul 03 14:28:35 volumio kernel: usb 1-1.3.2: Warning! Unlikely big volume range (=8065), cval->res is probably wrong. Jul 03 14:28:35 volumio kernel: usb 1-1.3.2: [11] FU [Line Playback Volume] ch = 2, val = -6144/1921/1 Jul 03 14:28:35 volumio kernel: usb 1-1.3.2: Warning! Unlikely big volume range (=6928), cval->res is probably wrong. Jul 03 14:28:35 volumio kernel: usb 1-1.3.2: [8] FU [Mic Capture Volume] ch = 2, val = -4096/2832/1 Jul 03 14:28:35 volumio kernel: usb 1-1.3.2: Warning! Unlikely big volume range (=6928), cval->res is probably wrong. Jul 03 14:28:35 volumio kernel: usb 1-1.3.2: [15] FU [Line Capture Volume] ch = 2, val = -4096/2832/1 Jul 03 14:28:35 volumio kernel: usb 1-1.3.2: Warning! Unlikely big volume range (=6928), cval->res is probably wrong. Jul 03 14:28:35 volumio kernel: usb 1-1.3.2: [2] FU [PCM Capture Volume] ch = 2, val = -4096/2832/1 Jul 03 14:28:35 volumio kernel: input: USB Sound Device as /devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.3/1-1.3.2/1-1.3.2:1.3/0003:0D8C:0102.0003/input/input11 Jul 03 14:28:35 volumio mpd[1881]: Jul 03 14:28 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 03 14:28:35 volumio kernel: hid-generic 0003:0D8C:0102.0003: input,hidraw0: USB HID v1.00 Device [USB Sound Device ] on usb-0000:00:1d.0-1.3.2/input3 Jul 03 14:28:36 volumio systemd[1]: Started Music Player Daemon. Jul 03 14:28:36 volumio sudo[1859]: pam_unix(sudo:session): session closed for user root Jul 03 14:28:36 volumio volumio[999]: error: updateQueue error: null Jul 03 14:28:36 volumio volumio[999]: info: No valid Plugin REST Endpoint Jul 03 14:28:36 volumio volumio[999]: info: Jul 03 14:28:36 volumio volumio[999]: ---------------------------- USB Audio Device Attached Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Jul 03 14:28:36 volumio systemd-udevd[1833]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::Close All Modals sent Jul 03 14:28:36 volumio volumio[999]: info: Preparing to save Alsa Options, stopping services first Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::volumioGetState Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::volumioPause Jul 03 14:28:36 volumio volumio[999]: info: CoreStateMachine::pause Jul 03 14:28:36 volumio volumio[999]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"ICUSBAUDIO7D","alsacard":"ICUSBAUDIO7D"},"i2s":false} Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 03 14:28:36 volumio volumio[999]: info: Setting mixer Speaker for card ICUSBAUDIO7D Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jul 03 14:28:36 volumio volumio[999]: info: Updating Volume Controller Parameters: Device: 5 Name: ICUSBAUDIO7D Mixer: Speaker Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jul 03 14:28:36 volumio volumio[999]: info: Disabling external Volume Control Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 14:28:36 volumio volumio[999]: info: Preparing to generate the ALSA configuration file Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 03 14:28:36 volumio volumio[999]: info: Asound.conf file unchanged, so no further update is needed Jul 03 14:28:36 volumio volumio[999]: info: Output device has changed, restarting MPD Jul 03 14:28:36 volumio sudo[1916]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 03 14:28:36 volumio volumio[999]: info: Output device has changed, restarting Shairport Sync Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 14:28:36 volumio sudo[1916]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 14:28:36 volumio sudo[1916]: pam_unix(sudo:session): session closed for user root Jul 03 14:28:36 volumio sudo[1918]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 03 14:28:36 volumio sudo[1918]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 14:28:36 volumio systemd[1]: Stopping Music Player Daemon... Jul 03 14:28:36 volumio volumio[999]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 03 14:28:36 volumio volumio[999]: info: MPD Permissions set Jul 03 14:28:36 volumio systemd[1]: mpd.service: Succeeded. Jul 03 14:28:36 volumio systemd[1]: Stopped Music Player Daemon. Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:36 volumio systemd[1]: Starting Music Player Daemon... Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:36 volumio volumio[999]: info: VolumeController:: Volume=100 Mute =false Jul 03 14:28:36 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:36 volumio volumio[999]: info: Starting Shairport Sync Jul 03 14:28:36 volumio sudo[1933]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 03 14:28:36 volumio sudo[1924]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 03 14:28:36 volumio sudo[1924]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 14:28:36 volumio sudo[1933]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 14:28:36 volumio sudo[1924]: pam_unix(sudo:session): session closed for user root Jul 03 14:28:36 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 03 14:28:36 volumio systemd[1]: shairport-sync.service: Succeeded. Jul 03 14:28:36 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jul 03 14:28:36 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 03 14:28:36 volumio sudo[1933]: pam_unix(sudo:session): session closed for user root Jul 03 14:28:36 volumio volumio[999]: info: Shairport-Sync Started Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat Jul 03 14:28:36 volumio kernel: usb 1-1.3.2: USB disconnect, device number 7 Jul 03 14:28:36 volumio volumio[999]: info: No valid Plugin REST Endpoint Jul 03 14:28:36 volumio volumio[999]: info: Jul 03 14:28:36 volumio volumio[999]: ---------------------------- USB Audio Device Detached Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: raat , onStop Jul 03 14:28:36 volumio volumio-remote-updater[615]: PROGRESS: 23, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:36 volumio volumio-remote-updater[615]: PROGRESS: 23, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:36 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:36 volumio volumio[999]: updateProgress Jul 03 14:28:36 volumio volumio[999]: { Jul 03 14:28:36 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:36 volumio volumio[999]: eta: '5m', Jul 03 14:28:36 volumio volumio[999]: progress: 23, Jul 03 14:28:36 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:36 volumio volumio[999]: } Jul 03 14:28:37 volumio mpd[1936]: Jul 03 14:28 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 03 14:28:37 volumio systemd[1]: Started Music Player Daemon. Jul 03 14:28:37 volumio sudo[1918]: pam_unix(sudo:session): session closed for user root Jul 03 14:28:37 volumio volumio[999]: error: updateQueue error: null Jul 03 14:28:37 volumio volumio-remote-updater[615]: PROGRESS: 23, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:37 volumio volumio-remote-updater[615]: PROGRESS: 24, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:37 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:37 volumio volumio[999]: updateProgress Jul 03 14:28:37 volumio volumio[999]: { Jul 03 14:28:37 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:37 volumio volumio[999]: eta: '5m', Jul 03 14:28:37 volumio volumio[999]: progress: 24, Jul 03 14:28:37 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:37 volumio volumio[999]: } Jul 03 14:28:38 volumio volumio[999]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Jul 03 14:28:38 volumio volumio[999]: info: CoreStateMachine::getcurrentVolume Jul 03 14:28:38 volumio volumio[999]: info: CoreCommandRouter::volumioRetrievevolume Jul 03 14:28:38 volumio volumio[999]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Jul 03 14:28:38 volumio volumio[999]: info: VolumeController:: Volume=undefined Mute =false Jul 03 14:28:38 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:38 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:38 volumio volumio[999]: info: CoreStateMachine::updateTrackBlock Jul 03 14:28:38 volumio volumio[999]: info: CorePlayQueue::getTrackBlock Jul 03 14:28:38 volumio volumio[999]: info: CoreCommandRouter::volumioRetrievevolume Jul 03 14:28:38 volumio volumio[999]: error: Cannot get ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Jul 03 14:28:38 volumio volumio[999]: info: VolumeController:: Volume=undefined Mute =false Jul 03 14:28:38 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:38 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:39 volumio volumio-remote-updater[615]: PROGRESS: 24, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:39 volumio volumio[999]: updateProgress Jul 03 14:28:39 volumio volumio[999]: { Jul 03 14:28:39 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:39 volumio volumio[999]: eta: '5m', Jul 03 14:28:39 volumio volumio[999]: progress: 24, Jul 03 14:28:39 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:39 volumio volumio[999]: } Jul 03 14:28:39 volumio kernel: usb 1-1.3.2: new full-speed USB device number 8 using ehci-pci Jul 03 14:28:39 volumio kernel: usb 1-1.3.2: New USB device found, idVendor=0d8c, idProduct=0102, bcdDevice= 0.10 Jul 03 14:28:39 volumio kernel: usb 1-1.3.2: New USB device strings: Mfr=0, Product=2, SerialNumber=0 Jul 03 14:28:39 volumio kernel: usb 1-1.3.2: Product: USB Sound Device Jul 03 14:28:39 volumio kernel: usb 1-1.3.2: current rate 30464 is different from the runtime rate 96000 Jul 03 14:28:39 volumio kernel: usb 1-1.3.2: Warning! Unlikely big volume range (=8065), cval->res is probably wrong. Jul 03 14:28:39 volumio kernel: usb 1-1.3.2: [9] FU [Mic Playback Volume] ch = 2, val = -6144/1921/1 Jul 03 14:28:39 volumio kernel: usb 1-1.3.2: Warning! Unlikely big volume range (=8065), cval->res is probably wrong. Jul 03 14:28:39 volumio kernel: usb 1-1.3.2: [11] FU [Line Playback Volume] ch = 2, val = -6144/1921/1 Jul 03 14:28:39 volumio kernel: usb 1-1.3.2: Warning! Unlikely big volume range (=6928), cval->res is probably wrong. Jul 03 14:28:39 volumio kernel: usb 1-1.3.2: [8] FU [Mic Capture Volume] ch = 2, val = -4096/2832/1 Jul 03 14:28:39 volumio kernel: usb 1-1.3.2: Warning! Unlikely big volume range (=6928), cval->res is probably wrong. Jul 03 14:28:39 volumio kernel: usb 1-1.3.2: [15] FU [Line Capture Volume] ch = 2, val = -4096/2832/1 Jul 03 14:28:39 volumio kernel: usb 1-1.3.2: Warning! Unlikely big volume range (=6928), cval->res is probably wrong. Jul 03 14:28:39 volumio kernel: usb 1-1.3.2: [2] FU [PCM Capture Volume] ch = 2, val = -4096/2832/1 Jul 03 14:28:39 volumio kernel: input: USB Sound Device as /devices/pci0000:00/0000:00:1d.0/usb1/1-1/1-1.3/1-1.3.2/1-1.3.2:1.3/0003:0D8C:0102.0004/input/input12 Jul 03 14:28:39 volumio kernel: hid-generic 0003:0D8C:0102.0004: input,hidraw0: USB HID v1.00 Device [USB Sound Device ] on usb-0000:00:1d.0-1.3.2/input3 Jul 03 14:28:39 volumio volumio[999]: info: No valid Plugin REST Endpoint Jul 03 14:28:39 volumio volumio[999]: info: Jul 03 14:28:39 volumio volumio[999]: ---------------------------- USB Audio Device Attached Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::Close All Modals sent Jul 03 14:28:39 volumio volumio[999]: info: Preparing to save Alsa Options, stopping services first Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::volumioGetState Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::volumioPause Jul 03 14:28:39 volumio volumio[999]: info: CoreStateMachine::pause Jul 03 14:28:39 volumio volumio[999]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"ICUSBAUDIO7D","alsacard":"ICUSBAUDIO7D"},"i2s":false} Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 03 14:28:39 volumio systemd-udevd[1833]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 03 14:28:39 volumio volumio[999]: info: Setting mixer Speaker for card ICUSBAUDIO7D Jul 03 14:28:39 volumio volumio-remote-updater[615]: PROGRESS: 24, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:39 volumio volumio-remote-updater[615]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::volumioUpdateVolumeSettings Jul 03 14:28:39 volumio volumio[999]: info: Updating Volume Controller Parameters: Device: 5 Name: ICUSBAUDIO7D Mixer: Speaker Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Jul 03 14:28:39 volumio volumio[999]: info: Disabling external Volume Control Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::getUIConfigOnPlugin Jul 03 14:28:39 volumio volumio[999]: info: Preparing to generate the ALSA configuration file Jul 03 14:28:39 volumio volumio[999]: info: Asound.conf file unchanged, so no further update is needed Jul 03 14:28:39 volumio volumio[999]: info: Output device has changed, restarting MPD Jul 03 14:28:39 volumio volumio[999]: info: Output device has changed, restarting Shairport Sync Jul 03 14:28:39 volumio sudo[1988]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jul 03 14:28:39 volumio sudo[1988]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 14:28:39 volumio sudo[1988]: pam_unix(sudo:session): session closed for user root Jul 03 14:28:39 volumio sudo[1990]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jul 03 14:28:39 volumio sudo[1990]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 14:28:39 volumio systemd[1]: Stopping Music Player Daemon... Jul 03 14:28:39 volumio volumio[999]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jul 03 14:28:39 volumio systemd[1]: mpd.service: Succeeded. Jul 03 14:28:39 volumio systemd[1]: Stopped Music Player Daemon. Jul 03 14:28:39 volumio systemd[1]: Starting Music Player Daemon... Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Jul 03 14:28:39 volumio volumio[999]: info: MPD Permissions set Jul 03 14:28:39 volumio volumio[999]: info: VolumeController:: Volume=100 Mute =false Jul 03 14:28:39 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:39 volumio sudo[1996]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jul 03 14:28:39 volumio sudo[1996]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 14:28:39 volumio volumio[999]: updateProgress Jul 03 14:28:39 volumio volumio[999]: { Jul 03 14:28:39 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:39 volumio volumio[999]: eta: '5m', Jul 03 14:28:39 volumio volumio[999]: progress: 25, Jul 03 14:28:39 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:39 volumio volumio[999]: } Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:39 volumio sudo[1996]: pam_unix(sudo:session): session closed for user root Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jul 03 14:28:39 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: system , getCPUCoresNumber Jul 03 14:28:40 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jul 03 14:28:40 volumio volumio[999]: info: Starting Shairport Sync Jul 03 14:28:40 volumio sudo[2010]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jul 03 14:28:40 volumio sudo[2010]: pam_unix(sudo:session): session opened for user root by (uid=0) Jul 03 14:28:40 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jul 03 14:28:40 volumio systemd[1]: shairport-sync.service: Succeeded. Jul 03 14:28:40 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jul 03 14:28:40 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jul 03 14:28:40 volumio sudo[2010]: pam_unix(sudo:session): session closed for user root Jul 03 14:28:40 volumio volumio[999]: info: Shairport-Sync Started Jul 03 14:28:40 volumio volumio[999]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Jul 03 14:28:40 volumio volumio[999]: info: CoreStateMachine::getcurrentVolume Jul 03 14:28:40 volumio volumio[999]: info: CoreCommandRouter::volumioRetrievevolume Jul 03 14:28:40 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat Jul 03 14:28:40 volumio volumio[999]: info: VolumeController:: Volume=100 Mute =false Jul 03 14:28:40 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:40 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:40 volumio volumio[999]: info: CoreStateMachine::updateTrackBlock Jul 03 14:28:40 volumio volumio[999]: info: CorePlayQueue::getTrackBlock Jul 03 14:28:40 volumio volumio[999]: info: CoreCommandRouter::volumioRetrievevolume Jul 03 14:28:40 volumio volumio[999]: info: VolumeController:: Volume=100 Mute =false Jul 03 14:28:40 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:40 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:42 volumio mpd[2002]: Jul 03 14:28 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jul 03 14:28:42 volumio systemd[1]: Started Music Player Daemon. Jul 03 14:28:42 volumio sudo[1990]: pam_unix(sudo:session): session closed for user root Jul 03 14:28:42 volumio volumio[999]: error: updateQueue error: null Jul 03 14:28:43 volumio volumio-remote-updater[615]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:43 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:43 volumio volumio-remote-updater[615]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:43 volumio volumio[999]: updateProgress Jul 03 14:28:43 volumio volumio[999]: { Jul 03 14:28:43 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:43 volumio volumio[999]: eta: '5m', Jul 03 14:28:43 volumio volumio[999]: progress: 25, Jul 03 14:28:43 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:43 volumio volumio[999]: } Jul 03 14:28:43 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:43 volumio volumio-remote-updater[615]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:43 volumio volumio[999]: updateProgress Jul 03 14:28:43 volumio volumio[999]: { Jul 03 14:28:43 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:43 volumio volumio[999]: eta: '5m', Jul 03 14:28:43 volumio volumio[999]: progress: 25, Jul 03 14:28:43 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:43 volumio volumio[999]: } Jul 03 14:28:43 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:43 volumio volumio[999]: updateProgress Jul 03 14:28:43 volumio volumio[999]: { Jul 03 14:28:43 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:43 volumio volumio[999]: eta: '5m', Jul 03 14:28:43 volumio volumio[999]: progress: 25, Jul 03 14:28:43 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:43 volumio volumio[999]: } Jul 03 14:28:43 volumio volumio[999]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Jul 03 14:28:43 volumio volumio[999]: info: CoreStateMachine::getcurrentVolume Jul 03 14:28:43 volumio volumio[999]: info: CoreCommandRouter::volumioRetrievevolume Jul 03 14:28:43 volumio volumio[999]: info: VolumeController:: Volume=100 Mute =false Jul 03 14:28:43 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:43 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:43 volumio volumio[999]: info: CoreStateMachine::updateTrackBlock Jul 03 14:28:43 volumio volumio[999]: info: CorePlayQueue::getTrackBlock Jul 03 14:28:43 volumio volumio[999]: info: CoreCommandRouter::volumioRetrievevolume Jul 03 14:28:43 volumio volumio[999]: info: VolumeController:: Volume=100 Mute =false Jul 03 14:28:43 volumio volumio[999]: info: CoreStateMachine::pushState Jul 03 14:28:43 volumio volumio[999]: info: CoreCommandRouter::volumioPushState Jul 03 14:28:44 volumio volumio-remote-updater[615]: PROGRESS: 25, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:44 volumio volumio-remote-updater[615]: PROGRESS: 28, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:44 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:44 volumio volumio[999]: updateProgress Jul 03 14:28:44 volumio volumio[999]: { Jul 03 14:28:44 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:44 volumio volumio[999]: eta: '5m', Jul 03 14:28:44 volumio volumio[999]: progress: 28, Jul 03 14:28:44 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:44 volumio volumio[999]: } Jul 03 14:28:44 volumio volumio-remote-updater[615]: PROGRESS: 28, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:44 volumio volumio-remote-updater[615]: PROGRESS: 30, STATUS: "Creating backup", ETA: "5m" Jul 03 14:28:44 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:44 volumio volumio[999]: updateProgress Jul 03 14:28:44 volumio volumio[999]: { Jul 03 14:28:44 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:44 volumio volumio[999]: eta: '5m', Jul 03 14:28:44 volumio volumio[999]: progress: 30, Jul 03 14:28:44 volumio volumio[999]: status: 'Creating backup' Jul 03 14:28:44 volumio volumio[999]: } Jul 03 14:28:47 volumio volumio-remote-updater[615]: /bin/cp: cannot stat '/imgpart/volumio_factory.sqsh': No such file or directory Jul 03 14:28:48 volumio volumio-remote-updater[615]: /bin/rm: cannot remove '/imgpart/volumio_factory.sqsh': No such file or directory Jul 03 14:28:48 volumio volumio-remote-updater[615]: PROGRESS: 30, STATUS: "Downloading new update", ETA: "4m" Jul 03 14:28:48 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: websocket , broadcastMessage Jul 03 14:28:48 volumio volumio[999]: updateProgress Jul 03 14:28:48 volumio volumio[999]: { Jul 03 14:28:48 volumio volumio[999]: downloadSpeed: '', Jul 03 14:28:48 volumio volumio[999]: eta: '4m', Jul 03 14:28:48 volumio volumio[999]: progress: 30, Jul 03 14:28:48 volumio volumio[999]: status: 'Downloading new update' Jul 03 14:28:48 volumio volumio[999]: } Jul 03 14:28:59 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alarm-clock , getAlarms Jul 03 14:29:15 volumio volumio[999]: info: CoreCommandRouter::Close All Modals sent Jul 03 14:29:20 volumio volumio[999]: info: CoreCommandRouter::executeOnPlugin: alarm-clock , getSleep Jul 03 14:29:24 volumio volumio[999]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 03 14:29:24 volumio volumio[999]: Error: connect ETIMEDOUT 108.160.165.48:443 Jul 03 14:29:24 volumio volumio[999]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { Jul 03 14:29:24 volumio volumio[999]: errno: -110, Jul 03 14:29:24 volumio volumio[999]: code: 'ETIMEDOUT', Jul 03 14:29:24 volumio volumio[999]: syscall: 'connect', Jul 03 14:29:24 volumio volumio[999]: address: '108.160.165.48', Jul 03 14:29:24 volumio volumio[999]: port: 443 Jul 03 14:29:24 volumio volumio[999]: } Jul 03 14:29:24 volumio volumio[999]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jul 03 14:29:25 volumio sudo[2169]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-07-03 14:28 Jul 03 14:29:25 volumio sudo[2169]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="e32c2c71ae78852844c70357816bdd871c155ab8" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 31 Mar 2025 07:27:48 PM CEST" VOLUMIO_VERSION="3.799" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="4bc1ecb08f34ad14b420d6678a2aef1b"