-- Logs begin at Wed 2025-06-11 15:17:03 MSK, end at Wed 2025-06-11 15:23:10 MSK. -- Jun 11 15:22:00 volumio volumio[1189]: info: MyVolumio token set successfully Jun 11 15:22:00 volumio volumio[1189]: info: MYVOLUMIO: Adding device Jun 11 15:22:00 volumio volumio[1189]: info: MYVOLUMIO: Evaluating Server Jun 11 15:22:01 volumio volumio[1189]: info: MyVolumio status changed Jun 11 15:22:01 volumio volumio[1189]: info: Streaming services startup Jun 11 15:22:01 volumio volumio[1189]: info: Starting Streaming Daemon Jun 11 15:22:01 volumio volumio[1189]: info: Removing browser output: myVolumio user plan is not superstar Jun 11 15:22:01 volumio volumio[1189]: info: Removing audio output: Jun 11 15:22:01 volumio volumio[1189]: info: Stoppping Tunnel 1 Jun 11 15:22:01 volumio sudo[1484]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jun 11 15:22:01 volumio sudo[1484]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 15:22:01 volumio sudo[1487]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jun 11 15:22:01 volumio sudo[1487]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 15:22:01 volumio sudo[1484]: pam_unix(sudo:session): session closed for user root Jun 11 15:22:01 volumio volumio[1189]: error: Cannot start Volumio Streaming Daemon Jun 11 15:22:01 volumio volumio[1189]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jun 11 15:22:01 volumio volumio[1189]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jun 11 15:22:01 volumio sudo[1487]: pam_unix(sudo:session): session closed for user root Jun 11 15:22:01 volumio volumio[1189]: info: Remote SSH Stopped Jun 11 15:22:01 volumio volumio[1189]: info: Setting Geolocation for MyVolumio to eu7 Jun 11 15:22:01 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 15:22:01 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 15:22:01 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 15:22:02 volumio systemd[1]: systemd-timedated.service: Succeeded. Jun 11 15:22:02 volumio volumio[1189]: info: Updating MyVolumio device info Jun 11 15:22:02 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 15:22:02 volumio volumio[1189]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jun 11 15:22:02 volumio volumio[1189]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jun 11 15:22:05 volumio volumio[1436]: .........................................................................................................++++ Jun 11 15:22:06 volumio volumio[1189]: info: MYVOLUMIO: Adding device Jun 11 15:22:06 volumio volumio[1189]: info: MYVOLUMIO: Evaluating Server Jun 11 15:22:07 volumio volumio[1189]: info: Setting Geolocation for MyVolumio to eu8 Jun 11 15:22:07 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 15:22:07 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 15:22:07 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 15:22:07 volumio volumio[1189]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jun 11 15:22:08 volumio volumio[1189]: info: Updating MyVolumio device info Jun 11 15:22:08 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 15:22:08 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 15:22:08 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 15:22:08 volumio volumio[1189]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jun 11 15:22:09 volumio volumio[1189]: info: Preload queue cleared Jun 11 15:22:09 volumio volumio[1189]: info: CoreCommandRouter::volumioReplaceandPlayItems Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::ClearQueue Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::stop Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 11 15:22:09 volumio volumio[1189]: info: CorePlayQueue::clearPlayQueue Jun 11 15:22:09 volumio volumio[1189]: info: CorePlayQueue::saveQueue Jun 11 15:22:09 volumio volumio[1189]: info: CoreCommandRouter::volumioPushQueue Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::addQueueItems Jun 11 15:22:09 volumio volumio[1189]: info: CorePlayQueue::addQueueItems Jun 11 15:22:09 volumio volumio[1189]: info: Preload queue cleared Jun 11 15:22:09 volumio volumio[1189]: info: Adding Item to queue: albums://C.%20C.%20Catch/C.%20C.%20Catch%20-%20Collection%20ALEXnROCK Jun 11 15:22:09 volumio volumio[1189]: info: Exploding uri albums://C.%20C.%20Catch/C.%20C.%20Catch%20-%20Collection%20ALEXnROCK in service mpd Jun 11 15:22:09 volumio volumio[1189]: info: CoreCommandRouter::volumioPushQueue Jun 11 15:22:09 volumio volumio[1189]: info: CorePlayQueue::saveQueue Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::updateTrackBlock Jun 11 15:22:09 volumio volumio[1189]: info: CorePlayQueue::getTrackBlock Jun 11 15:22:09 volumio volumio[1189]: info: CoreCommandRouter::volumioPlay Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::play index 0 Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::stop Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::play index undefined Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 11 15:22:09 volumio volumio[1189]: info: CorePlayQueue::getTrack 0 Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::startPlaybackTimer Jun 11 15:22:09 volumio volumio[1189]: info: CorePlayQueue::getTrack 0 Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::clearAddPlayTracks USB/LEEF/C. C. Catch - Collection FLAC/01. C.C. Catch - Cause You Are Young.flac Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand stop Jun 11 15:22:09 volumio volumio[1189]: info: sendMpdCommand stop took 7 milliseconds Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand clear Jun 11 15:22:09 volumio volumio[1189]: info: sendMpdCommand clear took 1 milliseconds Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand add "USB/LEEF/C. C. Catch - Collection FLAC/01. C.C. Catch - Cause You Are Young.flac" Jun 11 15:22:09 volumio volumio[1189]: info: Jun 11 15:22:09 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:22:09 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:22:09 volumio volumio[1189]: info: Jun 11 15:22:09 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:22:09 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:22:09 volumio volumio[1189]: info: sendMpdCommand add "USB/LEEF/C. C. Catch - Collection FLAC/01. C.C. Catch - Cause You Are Young.flac" took 22 milliseconds Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand play Jun 11 15:22:09 volumio volumio[1189]: info: Jun 11 15:22:09 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:22:09 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:22:09 volumio volumio[1189]: info: Jun 11 15:22:09 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:22:09 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:22:09 volumio volumio[1189]: info: ------------------------------ 7ms Jun 11 15:22:09 volumio volumio[1189]: info: ------------------------------ 6ms Jun 11 15:22:09 volumio volumio[1189]: info: sendMpdCommand play took 6 milliseconds Jun 11 15:22:09 volumio volumio[1189]: info: ------------------------------ 5ms Jun 11 15:22:09 volumio volumio[1189]: info: ------------------------------ 4ms Jun 11 15:22:09 volumio volumio[1189]: info: Jun 11 15:22:09 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:22:09 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:22:09 volumio volumio[1189]: info: Jun 11 15:22:09 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:22:09 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:22:09 volumio volumio[1189]: info: Jun 11 15:22:09 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:09 volumio volumio[1189]: info: Jun 11 15:22:09 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:09 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:09 volumio volumio[1189]: info: ------------------------------ 5ms Jun 11 15:22:09 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:09 volumio volumio[1189]: info: ------------------------------ 5ms Jun 11 15:22:09 volumio volumio[1189]: info: Jun 11 15:22:09 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:09 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:09 volumio volumio[1189]: info: Jun 11 15:22:09 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:09 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand clearerror Jun 11 15:22:09 volumio volumio[1189]: info: sendMpdCommand status took 12 milliseconds Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand clearerror Jun 11 15:22:09 volumio volumio[1189]: info: sendMpdCommand status took 13 milliseconds Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand clearerror Jun 11 15:22:09 volumio volumio[1189]: info: sendMpdCommand status took 11 milliseconds Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand clearerror Jun 11 15:22:09 volumio volumio[1189]: info: sendMpdCommand status took 10 milliseconds Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 11 15:22:09 volumio volumio[1189]: info: sendMpdCommand clearerror took 14 milliseconds Jun 11 15:22:09 volumio volumio[1189]: info: sendMpdCommand clearerror took 13 milliseconds Jun 11 15:22:09 volumio volumio[1189]: info: sendMpdCommand clearerror took 12 milliseconds Jun 11 15:22:09 volumio volumio[1189]: info: sendMpdCommand clearerror took 11 milliseconds Jun 11 15:22:09 volumio volumio[1189]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 11 15:22:09 volumio volumio[1189]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 11 15:22:09 volumio volumio[1189]: info: sendMpdCommand playlistinfo took 4 milliseconds Jun 11 15:22:09 volumio volumio[1189]: info: sendMpdCommand playlistinfo took 4 milliseconds Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::parseTrackInfo Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::parseTrackInfo Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::parseTrackInfo Jun 11 15:22:09 volumio volumio[1189]: verbose: ControllerMpd::parseTrackInfo Jun 11 15:22:09 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:09 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:09 volumio volumio[1189]: info: CorePlayQueue::getTrack 0 Jun 11 15:22:09 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":287,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Cause You Are Young","artist":"01. C.C. Catch","album":"C. C. Catch - Collection ALEXnROCK","uri":"USB/LEEF/C. C. Catch - Collection FLAC/01. C.C. Catch - Cause You Are Young.flac","trackType":"flac"} Jun 11 15:22:09 volumio volumio[1189]: verbose: CURRENT POSITION 0 Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:09 volumio volumio[1189]: info: CorePlayQueue::getTrack 0 Jun 11 15:22:09 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:09 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:09 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:09 volumio volumio[1189]: info: CorePlayQueue::getTrack 0 Jun 11 15:22:09 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":287,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Cause You Are Young","artist":"01. C.C. Catch","album":"C. C. Catch - Collection ALEXnROCK","uri":"USB/LEEF/C. C. Catch - Collection FLAC/01. C.C. Catch - Cause You Are Young.flac","trackType":"flac"} Jun 11 15:22:09 volumio volumio[1189]: verbose: CURRENT POSITION 0 Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:09 volumio volumio[1189]: info: CorePlayQueue::getTrack 0 Jun 11 15:22:09 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:09 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:09 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:09 volumio volumio[1189]: info: CorePlayQueue::getTrack 0 Jun 11 15:22:09 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":287,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Cause You Are Young","artist":"01. C.C. Catch","album":"C. C. Catch - Collection ALEXnROCK","uri":"USB/LEEF/C. C. Catch - Collection FLAC/01. C.C. Catch - Cause You Are Young.flac","trackType":"flac"} Jun 11 15:22:09 volumio volumio[1189]: verbose: CURRENT POSITION 0 Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:09 volumio volumio[1189]: info: CorePlayQueue::getTrack 0 Jun 11 15:22:09 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:09 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:09 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:09 volumio volumio[1189]: info: CorePlayQueue::getTrack 0 Jun 11 15:22:09 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":287,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Cause You Are Young","artist":"01. C.C. Catch","album":"C. C. Catch - Collection ALEXnROCK","uri":"USB/LEEF/C. C. Catch - Collection FLAC/01. C.C. Catch - Cause You Are Young.flac","trackType":"flac"} Jun 11 15:22:09 volumio volumio[1189]: verbose: CURRENT POSITION 0 Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:09 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:09 volumio volumio[1189]: info: CorePlayQueue::getTrack 0 Jun 11 15:22:09 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:09 volumio volumio[1189]: info: ------------------------------ 58ms Jun 11 15:22:09 volumio volumio[1189]: info: ------------------------------ 59ms Jun 11 15:22:09 volumio volumio[1189]: info: ------------------------------ 56ms Jun 11 15:22:09 volumio volumio[1189]: info: ------------------------------ 54ms Jun 11 15:22:09 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:09 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:09 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:09 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:13 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Jun 11 15:22:13 volumio volumio[1189]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 14 Jun 11 15:22:13 volumio volumio[1189]: info: CoreCommandRouter::volumioGetState Jun 11 15:22:13 volumio volumio[1189]: info: CorePlayQueue::getTrack 0 Jun 11 15:22:18 volumio volumio[1436]: ...........................................................................................................................................++++ Jun 11 15:22:18 volumio volumio[1436]: e is 65537 (0x010001) Jun 11 15:22:18 volumio volumio[1436]: writing RSA key Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::volumioGetBrowseSources Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jun 11 15:22:18 volumio volumio-remote-updater[766]: No test mode Jun 11 15:22:18 volumio volumio-remote-updater[766]: No alpha test mode Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jun 11 15:22:18 volumio volumio[1189]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::volumioNext Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::next Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::stop Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::play index undefined Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::startPlaybackTimer Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::clearAddPlayTracks USB/LEEF/C. C. Catch - Collection FLAC/02. C.C. Catch - Can Lose My Heart Tonight.flac Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand stop Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::updateTrackBlock Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrackBlock Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand stop took 2 milliseconds Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand clear Jun 11 15:22:18 volumio volumio[1189]: info: Jun 11 15:22:18 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:18 volumio volumio[1189]: info: Jun 11 15:22:18 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:22:18 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:22:18 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand clear took 2 milliseconds Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand add "USB/LEEF/C. C. Catch - Collection FLAC/02. C.C. Catch - Can Lose My Heart Tonight.flac" Jun 11 15:22:18 volumio volumio[1189]: info: Jun 11 15:22:18 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:18 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:18 volumio volumio[1189]: info: Jun 11 15:22:18 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:18 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:18 volumio volumio[1189]: error: updateQueue error: null Jun 11 15:22:18 volumio volumio[1189]: info: Jun 11 15:22:18 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:22:18 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand status took 4 milliseconds Jun 11 15:22:18 volumio volumio[1189]: info: ------------------------------ 5ms Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand add "USB/LEEF/C. C. Catch - Collection FLAC/02. C.C. Catch - Can Lose My Heart Tonight.flac" took 4 milliseconds Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand status took 3 milliseconds Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand status took 2 milliseconds Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand play Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:18 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jun 11 15:22:18 volumio volumio[1189]: verbose: CURRENT POSITION 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::syncState stateService stop Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:18 volumio volumio[1189]: info: No code Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:18 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jun 11 15:22:18 volumio volumio[1189]: verbose: CURRENT POSITION 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::syncState stateService stop Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:18 volumio volumio[1189]: info: No code Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:18 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jun 11 15:22:18 volumio volumio[1189]: verbose: CURRENT POSITION 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::syncState stateService stop Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:18 volumio volumio[1189]: info: No code Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:18 volumio volumio[1189]: info: ------------------------------ 55ms Jun 11 15:22:18 volumio volumio[1189]: info: ------------------------------ 53ms Jun 11 15:22:18 volumio volumio[1189]: info: ------------------------------ 53ms Jun 11 15:22:18 volumio volumio[1189]: info: Jun 11 15:22:18 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:22:18 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:22:18 volumio volumio[1189]: info: Jun 11 15:22:18 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:22:18 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:22:18 volumio volumio[1189]: info: Jun 11 15:22:18 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:18 volumio volumio[1189]: info: Jun 11 15:22:18 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:18 volumio volumio[1189]: info: ------------------------------ 56ms Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand play took 54 milliseconds Jun 11 15:22:18 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:18 volumio volumio[1189]: info: ------------------------------ 3ms Jun 11 15:22:18 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:18 volumio volumio[1189]: info: ------------------------------ 4ms Jun 11 15:22:18 volumio volumio[1189]: info: Jun 11 15:22:18 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:18 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:18 volumio volumio[1189]: info: Jun 11 15:22:18 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:18 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:18 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:18 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:18 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:18 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:18 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:18 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:18 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:18 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:18 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand clearerror Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand status took 24 milliseconds Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand clearerror Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand status took 24 milliseconds Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand clearerror Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand status took 24 milliseconds Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand clearerror Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand status took 24 milliseconds Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand clearerror took 15 milliseconds Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand clearerror took 14 milliseconds Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand clearerror took 13 milliseconds Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand clearerror took 12 milliseconds Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::parseTrackInfo Jun 11 15:22:18 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":352,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Can Lose My Heart Tonight","artist":"02. C.C. Catch","album":"C. C. Catch - Collection ALEXnROCK","uri":"USB/LEEF/C. C. Catch - Collection FLAC/02. C.C. Catch - Can Lose My Heart Tonight.flac","trackType":"flac"} Jun 11 15:22:18 volumio volumio[1189]: verbose: CURRENT POSITION 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:18 volumio volumio[1189]: info: ------------------------------ 49ms Jun 11 15:22:18 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand playlistinfo took 17 milliseconds Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand playlistinfo took 17 milliseconds Jun 11 15:22:18 volumio volumio[1189]: info: sendMpdCommand playlistinfo took 17 milliseconds Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::parseTrackInfo Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::parseTrackInfo Jun 11 15:22:18 volumio volumio[1189]: verbose: ControllerMpd::parseTrackInfo Jun 11 15:22:18 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":352,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Can Lose My Heart Tonight","artist":"02. C.C. Catch","album":"C. C. Catch - Collection ALEXnROCK","uri":"USB/LEEF/C. C. Catch - Collection FLAC/02. C.C. Catch - Can Lose My Heart Tonight.flac","trackType":"flac"} Jun 11 15:22:18 volumio volumio[1189]: verbose: CURRENT POSITION 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:18 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":352,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Can Lose My Heart Tonight","artist":"02. C.C. Catch","album":"C. C. Catch - Collection ALEXnROCK","uri":"USB/LEEF/C. C. Catch - Collection FLAC/02. C.C. Catch - Can Lose My Heart Tonight.flac","trackType":"flac"} Jun 11 15:22:18 volumio volumio[1189]: verbose: CURRENT POSITION 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:18 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":352,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Can Lose My Heart Tonight","artist":"02. C.C. Catch","album":"C. C. Catch - Collection ALEXnROCK","uri":"USB/LEEF/C. C. Catch - Collection FLAC/02. C.C. Catch - Can Lose My Heart Tonight.flac","trackType":"flac"} Jun 11 15:22:18 volumio volumio[1189]: verbose: CURRENT POSITION 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:18 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:18 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:18 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:18 volumio volumio[1189]: info: ------------------------------ 72ms Jun 11 15:22:18 volumio volumio[1189]: info: ------------------------------ 72ms Jun 11 15:22:18 volumio volumio[1189]: info: ------------------------------ 71ms Jun 11 15:22:18 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:18 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:18 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:19 volumio volumio[1189]: error: MyVolumio Plugin failed to authenticate in a timely fashion Jun 11 15:22:19 volumio volumio[1189]: info: Completed starting MyVolumio Plugin Jun 11 15:22:19 volumio volumio[1189]: [Metrics] CommandRouter: 36s 145.32ms Jun 11 15:22:19 volumio volumio[1189]: info: CoreCommandRouter::volumiosetStartupVolume Jun 11 15:22:19 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:22:19 volumio volumio[1189]: info: VolumeController:: Setting startup Volume 20 Jun 11 15:22:19 volumio volumio[1189]: info: VolumeController::SetAlsaVolume20 Jun 11 15:22:19 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 15:22:19 volumio volumio[1189]: info: CoreCommandRouter::Close All Modals sent Jun 11 15:22:19 volumio volumio[1189]: info: CoreCommandRouter::Close All Modals sent Jun 11 15:22:19 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:19 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:19 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 11 15:22:19 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:19 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:19 volumio volumio[1189]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Jun 11 15:22:19 volumio volumio[1189]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Jun 11 15:22:19 volumio volumio[1189]: ALSA lib pcm_softvol.c:778:(softvol_load_control) Cannot open CTL hw:2 Jun 11 15:22:19 volumio volumio[1189]: aplay: main:828: audio open error: No such file or directory Jun 11 15:22:20 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Jun 11 15:22:20 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Jun 11 15:22:20 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Jun 11 15:22:26 volumio volumio[1189]: info: BOOT COMPLETED Jun 11 15:22:28 volumio ntpd[906]: Soliciting pool server 192.36.143.130 Jun 11 15:22:28 volumio ntpd[906]: Soliciting pool server 193.106.93.116 Jun 11 15:22:29 volumio ntpd[906]: Soliciting pool server 176.123.165.98 Jun 11 15:22:29 volumio ntpd[906]: Soliciting pool server 195.90.182.235 Jun 11 15:22:30 volumio volumio[1189]: info: VolumeController::SetAlsaVolume100 Jun 11 15:22:30 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:30 volumio volumio[1189]: info: CorePlayQueue::getTrack 1 Jun 11 15:22:30 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 11 15:22:30 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:30 volumio ntpd[906]: Soliciting pool server 92.255.126.4 Jun 11 15:22:30 volumio ntpd[906]: Soliciting pool server 162.159.200.123 Jun 11 15:22:30 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:30 volumio volumio[1189]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Jun 11 15:22:31 volumio ntpd[906]: Soliciting pool server 92.255.126.12 Jun 11 15:22:31 volumio ntpd[906]: Soliciting pool server 51.250.110.169 Jun 11 15:22:31 volumio ntpd[906]: Soliciting pool server 178.217.98.201 Jun 11 15:22:32 volumio ntpd[906]: Soliciting pool server 91.206.16.3 Jun 11 15:22:32 volumio ntpd[906]: Soliciting pool server 51.250.53.172 Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::volumioNext Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::next Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::stop Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::play index undefined Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::startPlaybackTimer Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::clearAddPlayTracks USB/LEEF/C. C. Catch - Collection FLAC/03. C.C. Catch - You Shot A Hole In My Soul.flac Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand stop Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::updateTrackBlock Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrackBlock Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand stop took 2 milliseconds Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand clear Jun 11 15:22:32 volumio volumio[1189]: info: Jun 11 15:22:32 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:32 volumio volumio[1189]: info: Jun 11 15:22:32 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:22:32 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:22:32 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand clear took 2 milliseconds Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand add "USB/LEEF/C. C. Catch - Collection FLAC/03. C.C. Catch - You Shot A Hole In My Soul.flac" Jun 11 15:22:32 volumio volumio[1189]: info: Jun 11 15:22:32 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:32 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:32 volumio volumio[1189]: info: Jun 11 15:22:32 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:32 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:32 volumio volumio[1189]: error: updateQueue error: null Jun 11 15:22:32 volumio volumio[1189]: info: Jun 11 15:22:32 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:22:32 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand status took 5 milliseconds Jun 11 15:22:32 volumio volumio[1189]: info: ------------------------------ 6ms Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand add "USB/LEEF/C. C. Catch - Collection FLAC/03. C.C. Catch - You Shot A Hole In My Soul.flac" took 5 milliseconds Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand status took 3 milliseconds Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand status took 2 milliseconds Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand play Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:32 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jun 11 15:22:32 volumio volumio[1189]: verbose: CURRENT POSITION 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::syncState stateService stop Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:32 volumio volumio[1189]: info: No code Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:32 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jun 11 15:22:32 volumio volumio[1189]: verbose: CURRENT POSITION 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::syncState stateService stop Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:32 volumio volumio[1189]: info: No code Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:32 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Jun 11 15:22:32 volumio volumio[1189]: verbose: CURRENT POSITION 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::syncState stateService stop Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:32 volumio volumio[1189]: info: No code Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:32 volumio volumio[1189]: info: ------------------------------ 60ms Jun 11 15:22:32 volumio volumio[1189]: info: ------------------------------ 58ms Jun 11 15:22:32 volumio volumio[1189]: info: ------------------------------ 58ms Jun 11 15:22:32 volumio volumio[1189]: info: Jun 11 15:22:32 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:22:32 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:22:32 volumio volumio[1189]: info: Jun 11 15:22:32 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:22:32 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:22:32 volumio volumio[1189]: info: Jun 11 15:22:32 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:32 volumio volumio[1189]: info: Jun 11 15:22:32 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:32 volumio volumio[1189]: info: ------------------------------ 61ms Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand play took 59 milliseconds Jun 11 15:22:32 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:32 volumio volumio[1189]: info: ------------------------------ 4ms Jun 11 15:22:32 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:32 volumio volumio[1189]: info: ------------------------------ 4ms Jun 11 15:22:32 volumio volumio[1189]: info: Jun 11 15:22:32 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:32 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:32 volumio volumio[1189]: info: Jun 11 15:22:32 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:22:32 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:22:32 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:32 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:32 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:32 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:32 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:32 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:32 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:32 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:32 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand clearerror Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand status took 21 milliseconds Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand clearerror Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand status took 21 milliseconds Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand clearerror Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand status took 20 milliseconds Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand clearerror Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand status took 20 milliseconds Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand clearerror took 16 milliseconds Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand clearerror took 15 milliseconds Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand clearerror took 14 milliseconds Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand clearerror took 14 milliseconds Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 11 15:22:32 volumio volumio[1189]: info: sendMpdCommand playlistinfo took 4 milliseconds Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::parseTrackInfo Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::parseTrackInfo Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::parseTrackInfo Jun 11 15:22:32 volumio volumio[1189]: verbose: ControllerMpd::parseTrackInfo Jun 11 15:22:32 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":316,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"You Shot A Hole In My Soul","artist":"03. C.C. Catch","album":"C. C. Catch - Collection ALEXnROCK","uri":"USB/LEEF/C. C. Catch - Collection FLAC/03. C.C. Catch - You Shot A Hole In My Soul.flac","trackType":"flac"} Jun 11 15:22:32 volumio volumio[1189]: verbose: CURRENT POSITION 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:32 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":316,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"You Shot A Hole In My Soul","artist":"03. C.C. Catch","album":"C. C. Catch - Collection ALEXnROCK","uri":"USB/LEEF/C. C. Catch - Collection FLAC/03. C.C. Catch - You Shot A Hole In My Soul.flac","trackType":"flac"} Jun 11 15:22:32 volumio volumio[1189]: verbose: CURRENT POSITION 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:32 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":316,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"You Shot A Hole In My Soul","artist":"03. C.C. Catch","album":"C. C. Catch - Collection ALEXnROCK","uri":"USB/LEEF/C. C. Catch - Collection FLAC/03. C.C. Catch - You Shot A Hole In My Soul.flac","trackType":"flac"} Jun 11 15:22:32 volumio volumio[1189]: verbose: CURRENT POSITION 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:32 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":316,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"You Shot A Hole In My Soul","artist":"03. C.C. Catch","album":"C. C. Catch - Collection ALEXnROCK","uri":"USB/LEEF/C. C. Catch - Collection FLAC/03. C.C. Catch - You Shot A Hole In My Soul.flac","trackType":"flac"} Jun 11 15:22:32 volumio volumio[1189]: verbose: CURRENT POSITION 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::syncState stateService pause Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:22:32 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:22:32 volumio volumio[1189]: info: CorePlayQueue::getTrack 2 Jun 11 15:22:32 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:22:32 volumio volumio[1189]: info: ------------------------------ 70ms Jun 11 15:22:32 volumio volumio[1189]: info: ------------------------------ 70ms Jun 11 15:22:32 volumio volumio[1189]: info: ------------------------------ 68ms Jun 11 15:22:32 volumio volumio[1189]: info: ------------------------------ 67ms Jun 11 15:22:32 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:32 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:32 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:32 volumio volumio[1189]: info: [ASDebug] CurState: stop PrevState: stop Jun 11 15:22:33 volumio ntpd[906]: Soliciting pool server 92.255.126.3 Jun 11 15:22:33 volumio ntpd[906]: Soliciting pool server 51.250.35.68 Jun 11 15:22:34 volumio ntpd[906]: Soliciting pool server 92.255.126.17 Jun 11 15:22:34 volumio ntpd[906]: Soliciting pool server 92.255.126.1 Jun 11 15:22:35 volumio ntpd[906]: Soliciting pool server 2a00:ab00:203:9::1000:5 Jun 11 15:22:36 volumio ntpd[906]: receive: Unexpected origin timestamp 0xebf3f38b.2f204727 does not match aorg 0000000000.00000000 from server@91.206.16.3 xmt 0xebf3f38c.5c8de70a Jun 11 15:22:55 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 11 15:22:55 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 11 15:22:59 volumio volumio[1189]: info: Enabling plugin fusiondsp Jun 11 15:22:59 volumio volumio[1189]: info: Loading plugin "fusiondsp"... Jun 11 15:22:59 volumio volumio[1189]: info: Applying required configuration parameters for plugin fusiondsp Jun 11 15:22:59 volumio volumio[1189]: info: Preparing to generate the ALSA configuration file Jun 11 15:22:59 volumio volumio[1189]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jun 11 15:22:59 volumio volumio[1189]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jun 11 15:22:59 volumio volumio[1189]: info: Reading ALSA contributions from plugins. Jun 11 15:22:59 volumio volumio[1189]: info: Asound.conf file written Jun 11 15:22:59 volumio sudo[1680]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Jun 11 15:22:59 volumio sudo[1680]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 15:22:59 volumio sudo[1680]: pam_unix(sudo:session): session closed for user root Jun 11 15:23:00 volumio volumio[1189]: Found hardware: "RPi-WM8804" "" "" "" "" Jun 11 15:23:00 volumio volumio[1189]: Hardware is initialized using a generic method Jun 11 15:23:00 volumio volumio[1189]: info: Output device has changed, restarting MPD Jun 11 15:23:00 volumio sudo[1685]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 11 15:23:00 volumio sudo[1685]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 15:23:00 volumio volumio[1189]: info: Output device has changed, restarting Shairport Sync Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 15:23:00 volumio sudo[1685]: pam_unix(sudo:session): session closed for user root Jun 11 15:23:00 volumio sudo[1687]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 11 15:23:00 volumio sudo[1687]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 15:23:00 volumio systemd[1]: Stopping Music Player Daemon... Jun 11 15:23:00 volumio volumio[1189]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 11 15:23:00 volumio volumio[1189]: info: PLUGIN START: fusiondsp Jun 11 15:23:00 volumio volumio[1189]: info: Loading i18n strings for locale ru Jun 11 15:23:00 volumio systemd[1]: mpd.service: Succeeded. Jun 11 15:23:00 volumio systemd[1]: Stopped Music Player Daemon. Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: FusionDsp - mixtype--------------------- undefined Jun 11 15:23:00 volumio volumio[1189]: info: Preparing to generate the ALSA configuration file Jun 11 15:23:00 volumio volumio[1189]: info: Done. Jun 11 15:23:00 volumio volumio[1189]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Jun 11 15:23:00 volumio volumio[1189]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Jun 11 15:23:00 volumio volumio[1189]: info: Reading ALSA contributions from plugins. Jun 11 15:23:00 volumio volumio[1189]: info: MPD Permissions set Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: Starting Shairport Sync Jun 11 15:23:00 volumio systemd[1]: Starting Music Player Daemon... Jun 11 15:23:00 volumio volumio[1189]: info: Asound.conf file unchanged, so no further update is needed Jun 11 15:23:00 volumio volumio[1189]: info: Output device has changed, restarting MPD Jun 11 15:23:00 volumio sudo[1699]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 11 15:23:00 volumio sudo[1699]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 15:23:00 volumio sudo[1702]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jun 11 15:23:00 volumio sudo[1702]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 15:23:00 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 11 15:23:00 volumio sudo[1702]: pam_unix(sudo:session): session closed for user root Jun 11 15:23:00 volumio systemd[1]: shairport-sync.service: Succeeded. Jun 11 15:23:00 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 11 15:23:00 volumio volumio[1189]: info: Output device has changed, restarting Shairport Sync Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 15:23:00 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 11 15:23:00 volumio sudo[1699]: pam_unix(sudo:session): session closed for user root Jun 11 15:23:00 volumio sudo[1693]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 11 15:23:00 volumio sudo[1693]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 15:23:00 volumio sudo[1705]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jun 11 15:23:00 volumio sudo[1705]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 15:23:00 volumio sudo[1693]: pam_unix(sudo:session): session closed for user root Jun 11 15:23:00 volumio volumio[1189]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jun 11 15:23:00 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Jun 11 15:23:00 volumio systemd[1]: mpd.service: Succeeded. Jun 11 15:23:00 volumio systemd[1]: Stopped Music Player Daemon. Jun 11 15:23:00 volumio volumio[1189]: info: MPD Permissions set Jun 11 15:23:00 volumio volumio[1189]: info: Shairport-Sync Started Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio systemd[1]: Starting Music Player Daemon... Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:00 volumio volumio[1189]: info: Starting Shairport Sync Jun 11 15:23:00 volumio sudo[1721]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jun 11 15:23:00 volumio sudo[1721]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 15:23:00 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Jun 11 15:23:00 volumio systemd[1]: shairport-sync.service: Succeeded. Jun 11 15:23:00 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Jun 11 15:23:00 volumio sudo[1715]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jun 11 15:23:00 volumio sudo[1715]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 15:23:00 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Jun 11 15:23:00 volumio sudo[1715]: pam_unix(sudo:session): session closed for user root Jun 11 15:23:00 volumio sudo[1721]: pam_unix(sudo:session): session closed for user root Jun 11 15:23:00 volumio volumio[1189]: info: Shairport-Sync Started Jun 11 15:23:00 volumio mpd[1725]: Jun 11 15:23 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jun 11 15:23:00 volumio systemd[1]: Started Music Player Daemon. Jun 11 15:23:00 volumio sudo[1687]: pam_unix(sudo:session): session closed for user root Jun 11 15:23:00 volumio sudo[1705]: pam_unix(sudo:session): session closed for user root Jun 11 15:23:00 volumio volumio[1189]: error: MPD error: The expression evaluated to a falsy value: Jun 11 15:23:00 volumio volumio[1189]: assert.ok(self.idling) Jun 11 15:23:00 volumio volumio[1189]: error: The expression evaluated to a falsy value: Jun 11 15:23:00 volumio volumio[1189]: assert.ok(self.idling) Jun 11 15:23:00 volumio volumio[1189]: error: updateQueue error: null Jun 11 15:23:02 volumio volumio[1189]: info: camilladsp service started and running in background, instance 1 Jun 11 15:23:02 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jun 11 15:23:02 volumio volumio[1189]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA Jun 11 15:23:02 volumio volumio[1189]: info: FusionDsp loaded Jun 11 15:23:02 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Jun 11 15:23:02 volumio sudo[1740]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Jun 11 15:23:02 volumio sudo[1740]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 11 15:23:02 volumio volumio[1189]: info: FusionDsp - Reporting Fusion DSP Enabled Jun 11 15:23:02 volumio volumio[1189]: info: Adding Signal Path Element [object Object] Jun 11 15:23:02 volumio volumio[1189]: info: Adding fusiondspeq DSP Signal Path Element Jun 11 15:23:02 volumio volumio[1189]: info: FusionDsp - ---- installed callbackRead Jun 11 15:23:02 volumio volumio[1189]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 11 15:23:02 volumio volumio[1189]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 Jun 11 15:23:02 volumio volumio[1189]: error: FusionDsp - WebSocket error: [object Object] Jun 11 15:23:02 volumio systemd[1]: Started FusionDsp Daemon. Jun 11 15:23:02 volumio sudo[1740]: pam_unix(sudo:session): session closed for user root Jun 11 15:23:10 volumio volumio[1189]: info: CoreCommandRouter::volumioNext Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::next Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::stop Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::play index undefined Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 11 15:23:10 volumio volumio[1189]: info: CorePlayQueue::getTrack 3 Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::startPlaybackTimer Jun 11 15:23:10 volumio volumio[1189]: info: CorePlayQueue::getTrack 3 Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::clearAddPlayTracks USB/LEEF/C. C. Catch - Collection FLAC/04. C.C. Catch - One Night's Not Enough.flac Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand stop Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::updateTrackBlock Jun 11 15:23:10 volumio volumio[1189]: info: CorePlayQueue::getTrackBlock Jun 11 15:23:10 volumio volumio[1189]: info: sendMpdCommand stop took 2 milliseconds Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand clear Jun 11 15:23:10 volumio volumio[1189]: info: Jun 11 15:23:10 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:23:10 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:23:10 volumio volumio[1189]: info: sendMpdCommand clear took 1 milliseconds Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand add "USB/LEEF/C. C. Catch - Collection FLAC/04. C.C. Catch - One Night's Not Enough.flac" Jun 11 15:23:10 volumio volumio[1189]: info: Jun 11 15:23:10 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:23:10 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:23:10 volumio volumio[1189]: error: updateQueue error: null Jun 11 15:23:10 volumio volumio[1189]: info: Jun 11 15:23:10 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:23:10 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:23:10 volumio volumio[1189]: info: ------------------------------ 4ms Jun 11 15:23:10 volumio volumio[1189]: info: sendMpdCommand add "USB/LEEF/C. C. Catch - Collection FLAC/04. C.C. Catch - One Night's Not Enough.flac" took 3 milliseconds Jun 11 15:23:10 volumio volumio[1189]: info: ------------------------------ 2ms Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand play Jun 11 15:23:10 volumio volumio[1189]: info: Jun 11 15:23:10 volumio volumio[1189]: ---------------------------- MPD announces system playlist update Jun 11 15:23:10 volumio volumio[1189]: info: Ignoring MPD Status Update Jun 11 15:23:10 volumio volumio[1189]: info: ------------------------------ 4ms Jun 11 15:23:10 volumio volumio[1189]: info: sendMpdCommand play took 2 milliseconds Jun 11 15:23:10 volumio volumio[1189]: info: ------------------------------ 3ms Jun 11 15:23:10 volumio volumio[1189]: info: Jun 11 15:23:10 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:23:10 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:23:10 volumio volumio[1189]: info: Jun 11 15:23:10 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:23:10 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:23:10 volumio volumio[1189]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Jun 11 15:23:10 volumio volumio[1189]: info: FusionDsp - ---- read samplerate from file: 44100 Jun 11 15:23:10 volumio volumio[1189]: info: camilladsp stopping service pid 3316... Jun 11 15:23:10 volumio volumio[1189]: info: camilladsp service terminated, instance 1 Jun 11 15:23:10 volumio volumio[1189]: info: FusionDsp - If filter freq >samplerate/2 then disable it Jun 11 15:23:10 volumio volumio[1189]: info: camilladsp service started and running in background, instance 1 Jun 11 15:23:10 volumio volumio[1189]: info: Jun 11 15:23:10 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:23:10 volumio volumio[1189]: info: sendMpdCommand status took 33 milliseconds Jun 11 15:23:10 volumio volumio[1189]: info: sendMpdCommand status took 32 milliseconds Jun 11 15:23:10 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 11 15:23:10 volumio volumio[1189]: info: Jun 11 15:23:10 volumio volumio[1189]: ---------------------------- MPD announces state update: player Jun 11 15:23:10 volumio volumio[1189]: info: ControllerMpd::getState Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand status Jun 11 15:23:10 volumio volumio[1189]: info: sendMpdCommand status took 5 milliseconds Jun 11 15:23:10 volumio volumio[1189]: info: sendMpdCommand playlistinfo took 4 milliseconds Jun 11 15:23:10 volumio volumio[1189]: info: sendMpdCommand playlistinfo took 5 milliseconds Jun 11 15:23:10 volumio volumio[1189]: info: sendMpdCommand status took 3 milliseconds Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::parseTrackInfo Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::parseTrackInfo Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::parseState Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 11 15:23:10 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:23:10 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:23:10 volumio volumio[1189]: info: CorePlayQueue::getTrack 3 Jun 11 15:23:10 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":201,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"982 Kbps","isStreaming":false,"title":"One Night's Not Enough","artist":"04. C.C. Catch","album":"C. C. Catch - Collection ALEXnROCK","uri":"USB/LEEF/C. C. Catch - Collection FLAC/04. C.C. Catch - One Night's Not Enough.flac","trackType":"flac"} Jun 11 15:23:10 volumio volumio[1189]: verbose: CURRENT POSITION 3 Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus stop Jun 11 15:23:10 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:23:10 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:23:10 volumio volumio[1189]: info: CorePlayQueue::getTrack 3 Jun 11 15:23:10 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","position":0,"seek":91,"duration":201,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"982 Kbps","isStreaming":false,"title":"One Night's Not Enough","artist":"04. C.C. Catch","album":"C. C. Catch - Collection ALEXnROCK","uri":"USB/LEEF/C. C. Catch - Collection FLAC/04. C.C. Catch - One Night's Not Enough.flac","trackType":"flac"} Jun 11 15:23:10 volumio volumio[1189]: verbose: CURRENT POSITION 3 Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play Jun 11 15:23:10 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:23:10 volumio volumio[1189]: info: CorePlayQueue::getTrack 3 Jun 11 15:23:10 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 11 15:23:10 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:23:10 volumio volumio[1189]: info: CorePlayQueue::getTrack 3 Jun 11 15:23:10 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:23:10 volumio volumio[1189]: info: ------------------------------ 51ms Jun 11 15:23:10 volumio volumio[1189]: info: ------------------------------ 57ms Jun 11 15:23:10 volumio volumio[1189]: info: sendMpdCommand playlistinfo took 34 milliseconds Jun 11 15:23:10 volumio volumio[1189]: info: sendMpdCommand playlistinfo took 33 milliseconds Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::parseTrackInfo Jun 11 15:23:10 volumio volumio[1189]: verbose: ControllerMpd::parseTrackInfo Jun 11 15:23:10 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:23:10 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:23:10 volumio volumio[1189]: info: CorePlayQueue::getTrack 3 Jun 11 15:23:10 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":201,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"836 Kbps","isStreaming":false,"title":"One Night's Not Enough","artist":"04. C.C. Catch","album":"C. C. Catch - Collection ALEXnROCK","uri":"USB/LEEF/C. C. Catch - Collection FLAC/04. C.C. Catch - One Night's Not Enough.flac","trackType":"flac"} Jun 11 15:23:10 volumio volumio[1189]: verbose: CURRENT POSITION 3 Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play Jun 11 15:23:10 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:23:10 volumio volumio[1189]: info: CorePlayQueue::getTrack 3 Jun 11 15:23:10 volumio volumio[1189]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 11 15:23:10 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:23:10 volumio volumio[1189]: info: CorePlayQueue::getTrack 3 Jun 11 15:23:10 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:23:10 volumio volumio[1189]: info: ControllerMpd::pushState Jun 11 15:23:10 volumio volumio[1189]: info: CoreCommandRouter::servicePushState Jun 11 15:23:10 volumio volumio[1189]: info: CorePlayQueue::getTrack 3 Jun 11 15:23:10 volumio volumio[1189]: verbose: STATE SERVICE {"status":"play","position":0,"seek":960,"duration":201,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"836 Kbps","isStreaming":false,"title":"One Night's Not Enough","artist":"04. C.C. Catch","album":"C. C. Catch - Collection ALEXnROCK","uri":"USB/LEEF/C. C. Catch - Collection FLAC/04. C.C. Catch - One Night's Not Enough.flac","trackType":"flac"} Jun 11 15:23:10 volumio volumio[1189]: verbose: CURRENT POSITION 3 Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::syncState stateService play Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::syncState currentStatus play Jun 11 15:23:10 volumio volumio[1189]: info: Received an update from plugin. extracting info from payload Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:23:10 volumio volumio[1189]: info: CorePlayQueue::getTrack 3 Jun 11 15:23:10 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:23:10 volumio volumio[1189]: info: CoreStateMachine::pushState Jun 11 15:23:10 volumio volumio[1189]: info: CorePlayQueue::getTrack 3 Jun 11 15:23:10 volumio volumio[1189]: info: CoreCommandRouter::volumioPushState Jun 11 15:23:10 volumio volumio[1189]: info: ------------------------------ 79ms Jun 11 15:23:10 volumio volumio[1189]: info: ------------------------------ 76ms Jun 11 15:23:10 volumio volumio[1189]: info: [ASDebug] CurState: play PrevState: stop Jun 11 15:23:10 volumio volumio[1189]: info: [ASDebug] Togle GPIO: ON Jun 11 15:23:10 volumio volumio[1189]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 11 15:23:10 volumio volumio[1189]: Error: ESPIPE: invalid seek, write Jun 11 15:23:10 volumio volumio[1189]: at Object.writeSync (fs.js:711:3) Jun 11 15:23:10 volumio volumio[1189]: at Gpio.writeSync (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:243:8) Jun 11 15:23:10 volumio volumio[1189]: at AmpSwitchController.on (/data/plugins/system_controller/ampswitch/index.js:207:23) Jun 11 15:23:10 volumio volumio[1189]: at AmpSwitchController.parseStatus (/data/plugins/system_controller/ampswitch/index.js:190:86) Jun 11 15:23:10 volumio volumio[1189]: at Socket.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) Jun 11 15:23:10 volumio volumio[1189]: at Socket.onevent (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/socket.js:278:10) Jun 11 15:23:10 volumio volumio[1189]: at Socket.onpacket (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/socket.js:236:12) Jun 11 15:23:10 volumio volumio[1189]: at Manager. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) Jun 11 15:23:10 volumio volumio[1189]: at Manager.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) Jun 11 15:23:10 volumio volumio[1189]: at Manager.ondecoded (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/manager.js:349:8) Jun 11 15:23:10 volumio volumio[1189]: at Decoder. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) Jun 11 15:23:10 volumio volumio[1189]: at Decoder.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) Jun 11 15:23:10 volumio volumio[1189]: at Decoder.add (/data/plugins/system_controller/ampswitch/node_modules/socket.io-parser/index.js:254:12) Jun 11 15:23:10 volumio volumio[1189]: at Manager.ondata (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/manager.js:339:16) Jun 11 15:23:10 volumio volumio[1189]: at Socket. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) Jun 11 15:23:10 volumio volumio[1189]: at Socket.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) { Jun 11 15:23:10 volumio volumio[1189]: errno: -29, Jun 11 15:23:10 volumio volumio[1189]: syscall: 'write', Jun 11 15:23:10 volumio volumio[1189]: code: 'ESPIPE' Jun 11 15:23:10 volumio volumio[1189]: } Jun 11 15:23:10 volumio volumio[1189]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 11 15:23:10 volumio sudo[3342]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-11 15:22 Jun 11 15:23:10 volumio sudo[3342]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"