-- Logs begin at Tue 2025-06-17 13:21:55 -04, end at Tue 2025-06-17 13:33:34 -04. -- Jun 17 13:32:05 volumio volumio[835]: info: CoreCommandRouter::volumioPlay Jun 17 13:32:05 volumio volumio[835]: info: CoreStateMachine::play index undefined Jun 17 13:32:05 volumio volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 17 13:32:05 volumio volumio[835]: info: CorePlayQueue::getTrack 2 Jun 17 13:32:07 volumio volumio[835]: info: CoreCommandRouter::volumioPlay Jun 17 13:32:07 volumio volumio[835]: info: CoreStateMachine::play index undefined Jun 17 13:32:07 volumio volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 17 13:32:07 volumio volumio[835]: info: CorePlayQueue::getTrack 2 Jun 17 13:32:10 volumio volumio[835]: info: CoreCommandRouter::volumioPlay Jun 17 13:32:10 volumio volumio[835]: info: CoreStateMachine::play index undefined Jun 17 13:32:10 volumio volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 17 13:32:10 volumio volumio[835]: info: CorePlayQueue::getTrack 2 Jun 17 13:32:12 volumio volumio[835]: info: CoreCommandRouter::volumioNext Jun 17 13:32:12 volumio volumio[835]: info: CoreStateMachine::next Jun 17 13:32:12 volumio volumio[835]: info: CoreStateMachine::stop Jun 17 13:32:12 volumio volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 17 13:32:12 volumio volumio[835]: info: CoreStateMachine::stPlaybackTimer Jun 17 13:32:12 volumio volumio[835]: info: CoreStateMachine::updateTrackBlock Jun 17 13:32:12 volumio volumio[835]: info: CorePlayQueue::getTrackBlock Jun 17 13:32:12 volumio volumio[835]: info: CoreStateMachine::pushState Jun 17 13:32:12 volumio volumio[835]: info: CorePlayQueue::getTrack 2 Jun 17 13:32:12 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Jun 17 13:32:12 volumio volumio[835]: info: CoreStateMachine::serviceStop Jun 17 13:32:12 volumio volumio[835]: info: CorePlayQueue::getTrack 2 Jun 17 13:32:12 volumio volumio[835]: info: CoreCommandRouter::serviceStop Jun 17 13:32:12 volumio volumio[835]: info: ControllerMpd::stop Jun 17 13:32:12 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand stop Jun 17 13:32:12 volumio volumio[835]: info: [ASDebug] CurState: stop PrevState: stop Jun 17 13:32:12 volumio volumio[835]: info: Jun 17 13:32:12 volumio volumio[835]: ---------------------------- MPD announces state update: player Jun 17 13:32:12 volumio volumio[835]: info: sendMpdCommand stop took 58 milliseconds Jun 17 13:32:12 volumio volumio[835]: info: ControllerMpd::getState Jun 17 13:32:12 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand status Jun 17 13:32:12 volumio volumio[835]: info: CoreStateMachine::play index undefined Jun 17 13:32:12 volumio volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 17 13:32:12 volumio volumio[835]: info: CorePlayQueue::getTrack 3 Jun 17 13:32:12 volumio volumio[835]: info: CoreStateMachine::startPlaybackTimer Jun 17 13:32:12 volumio volumio[835]: info: CorePlayQueue::getTrack 3 Jun 17 13:32:12 volumio volumio[835]: verbose: ControllerMpd::clearAddPlayTracks NAS/ServiNas/Phil Collins - The Singles [1-3]/04 - Thru These Walls.mp3 Jun 17 13:32:12 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand stop Jun 17 13:32:12 volumio volumio[835]: info: CoreStateMachine::updateTrackBlock Jun 17 13:32:12 volumio volumio[835]: info: CorePlayQueue::getTrackBlock Jun 17 13:32:12 volumio volumio[835]: info: sendMpdCommand status took 27 milliseconds Jun 17 13:32:12 volumio volumio[835]: info: sendMpdCommand stop took 12 milliseconds Jun 17 13:32:12 volumio volumio[835]: verbose: ControllerMpd::parseState Jun 17 13:32:12 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 17 13:32:12 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand clear Jun 17 13:32:12 volumio volumio[835]: info: Jun 17 13:32:12 volumio volumio[835]: ---------------------------- MPD announces system playlist update Jun 17 13:32:12 volumio volumio[835]: info: Ignoring MPD Status Update Jun 17 13:32:12 volumio volumio[835]: info: sendMpdCommand playlistinfo took 14 milliseconds Jun 17 13:32:12 volumio volumio[835]: info: sendMpdCommand clear took 14 milliseconds Jun 17 13:32:12 volumio volumio[835]: verbose: ControllerMpd::parseTrackInfo Jun 17 13:32:12 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand add "NAS/ServiNas/Phil Collins - The Singles [1-3]/04 - Thru These Walls.mp3" Jun 17 13:32:12 volumio volumio[835]: info: ControllerMpd::pushState Jun 17 13:32:12 volumio volumio[835]: info: CoreCommandRouter::servicePushState Jun 17 13:32:12 volumio volumio[835]: info: CoreStateMachine::pushState Jun 17 13:32:12 volumio volumio[835]: info: CorePlayQueue::getTrack 3 Jun 17 13:32:12 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 17 13:32:12 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Jun 17 13:32:12 volumio volumio[835]: info: CorePlayQueue::getTrack 3 Jun 17 13:32:12 volumio volumio[835]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"If Leaving Me Is Easy","artist":"Phil Collins","album":"The Singles","uri":"NAS/ServiNas/Phil Collins - The Singles [1-3]/03 - If Leaving Me Is Easy.mp3","trackType":"mp3"} Jun 17 13:32:12 volumio volumio[835]: verbose: CURRENT POSITION 3 Jun 17 13:32:12 volumio volumio[835]: info: CoreStateMachine::syncState stateService stop Jun 17 13:32:12 volumio volumio[835]: info: CoreStateMachine::syncState currentStatus stop Jun 17 13:32:12 volumio volumio[835]: info: CoreStateMachine::pushState Jun 17 13:32:12 volumio volumio[835]: info: CorePlayQueue::getTrack 3 Jun 17 13:32:12 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Jun 17 13:32:12 volumio volumio[835]: info: No code Jun 17 13:32:12 volumio volumio[835]: info: CoreStateMachine::pushState Jun 17 13:32:12 volumio volumio[835]: info: CorePlayQueue::getTrack 3 Jun 17 13:32:12 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Jun 17 13:32:12 volumio volumio[835]: info: ------------------------------ 256ms Jun 17 13:32:12 volumio volumio[835]: error: updateQueue error: null Jun 17 13:32:12 volumio volumio[835]: info: Jun 17 13:32:12 volumio volumio[835]: ---------------------------- MPD announces system playlist update Jun 17 13:32:12 volumio volumio[835]: info: Ignoring MPD Status Update Jun 17 13:32:12 volumio volumio[835]: info: ------------------------------ 215ms Jun 17 13:32:12 volumio volumio[835]: info: sendMpdCommand add "NAS/ServiNas/Phil Collins - The Singles [1-3]/04 - Thru These Walls.mp3" took 203 milliseconds Jun 17 13:32:12 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand play Jun 17 13:32:12 volumio volumio[835]: info: [ASDebug] CurState: stop PrevState: stop Jun 17 13:32:12 volumio volumio[835]: info: [ASDebug] CurState: stop PrevState: stop Jun 17 13:32:12 volumio volumio[835]: info: [ASDebug] CurState: stop PrevState: stop Jun 17 13:32:12 volumio volumio[835]: info: Jun 17 13:32:12 volumio volumio[835]: ---------------------------- MPD announces state update: player Jun 17 13:32:12 volumio volumio[835]: info: ------------------------------ 251ms Jun 17 13:32:12 volumio volumio[835]: info: sendMpdCommand play took 243 milliseconds Jun 17 13:32:12 volumio volumio[835]: info: ControllerMpd::getState Jun 17 13:32:12 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand status Jun 17 13:32:12 volumio volumio[835]: info: sendMpdCommand status took 10 milliseconds Jun 17 13:32:12 volumio volumio[835]: verbose: ControllerMpd::parseState Jun 17 13:32:12 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 17 13:32:12 volumio volumio[835]: info: sendMpdCommand playlistinfo took 12 milliseconds Jun 17 13:32:12 volumio volumio[835]: verbose: ControllerMpd::parseTrackInfo Jun 17 13:32:12 volumio volumio[835]: info: ControllerMpd::pushState Jun 17 13:32:12 volumio volumio[835]: info: CoreCommandRouter::servicePushState Jun 17 13:32:12 volumio volumio[835]: info: CorePlayQueue::getTrack 3 Jun 17 13:32:13 volumio volumio[835]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":281,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Thru These Walls","artist":"Phil Collins","album":"The Singles","uri":"NAS/ServiNas/Phil Collins - The Singles [1-3]/04 - Thru These Walls.mp3","trackType":"mp3"} Jun 17 13:32:13 volumio volumio[835]: verbose: CURRENT POSITION 3 Jun 17 13:32:13 volumio volumio[835]: info: CoreStateMachine::syncState stateService play Jun 17 13:32:13 volumio volumio[835]: info: CoreStateMachine::syncState currentStatus stop Jun 17 13:32:13 volumio volumio[835]: info: ------------------------------ 100ms Jun 17 13:32:17 volumio volumio[835]: info: CoreCommandRouter::volumioPlay Jun 17 13:32:17 volumio volumio[835]: info: CoreStateMachine::play index undefined Jun 17 13:32:17 volumio volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 17 13:32:17 volumio volumio[835]: info: CorePlayQueue::getTrack 3 Jun 17 13:32:26 volumio volumio[835]: info: CoreCommandRouter::volumioPlay Jun 17 13:32:26 volumio volumio[835]: info: CoreStateMachine::play index undefined Jun 17 13:32:26 volumio volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 17 13:32:26 volumio volumio[835]: info: CorePlayQueue::getTrack 3 Jun 17 13:32:27 volumio volumio[835]: info: CoreCommandRouter::volumioNext Jun 17 13:32:27 volumio volumio[835]: info: CoreStateMachine::next Jun 17 13:32:27 volumio volumio[835]: info: CoreStateMachine::stop Jun 17 13:32:27 volumio volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 17 13:32:27 volumio volumio[835]: info: CoreStateMachine::stPlaybackTimer Jun 17 13:32:27 volumio volumio[835]: info: CoreStateMachine::updateTrackBlock Jun 17 13:32:27 volumio volumio[835]: info: CorePlayQueue::getTrackBlock Jun 17 13:32:27 volumio volumio[835]: info: CoreStateMachine::pushState Jun 17 13:32:27 volumio volumio[835]: info: CorePlayQueue::getTrack 3 Jun 17 13:32:27 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Jun 17 13:32:27 volumio volumio[835]: info: CoreStateMachine::serviceStop Jun 17 13:32:27 volumio volumio[835]: info: CorePlayQueue::getTrack 3 Jun 17 13:32:27 volumio volumio[835]: info: CoreCommandRouter::serviceStop Jun 17 13:32:27 volumio volumio[835]: info: ControllerMpd::stop Jun 17 13:32:27 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand stop Jun 17 13:32:27 volumio volumio[835]: info: [ASDebug] CurState: stop PrevState: stop Jun 17 13:32:27 volumio volumio[835]: info: Jun 17 13:32:27 volumio volumio[835]: ---------------------------- MPD announces state update: player Jun 17 13:32:27 volumio volumio[835]: info: sendMpdCommand stop took 64 milliseconds Jun 17 13:32:27 volumio volumio[835]: info: ControllerMpd::getState Jun 17 13:32:27 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand status Jun 17 13:32:28 volumio volumio[835]: info: CoreStateMachine::play index undefined Jun 17 13:32:28 volumio volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 17 13:32:28 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:32:28 volumio volumio[835]: info: CoreStateMachine::startPlaybackTimer Jun 17 13:32:28 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:32:28 volumio volumio[835]: verbose: ControllerMpd::clearAddPlayTracks NAS/ServiNas/Phil Collins - The Singles [1-3]/05 - You Can't Hurry Love.mp3 Jun 17 13:32:28 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand stop Jun 17 13:32:28 volumio volumio[835]: info: CoreStateMachine::updateTrackBlock Jun 17 13:32:28 volumio volumio[835]: info: CorePlayQueue::getTrackBlock Jun 17 13:32:28 volumio volumio[835]: info: sendMpdCommand status took 27 milliseconds Jun 17 13:32:28 volumio volumio[835]: info: sendMpdCommand stop took 11 milliseconds Jun 17 13:32:28 volumio volumio[835]: verbose: ControllerMpd::parseState Jun 17 13:32:28 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 17 13:32:28 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand clear Jun 17 13:32:28 volumio volumio[835]: info: Jun 17 13:32:28 volumio volumio[835]: ---------------------------- MPD announces system playlist update Jun 17 13:32:28 volumio volumio[835]: info: Ignoring MPD Status Update Jun 17 13:32:28 volumio volumio[835]: info: sendMpdCommand playlistinfo took 15 milliseconds Jun 17 13:32:28 volumio volumio[835]: info: sendMpdCommand clear took 15 milliseconds Jun 17 13:32:28 volumio volumio[835]: verbose: ControllerMpd::parseTrackInfo Jun 17 13:32:28 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand add "NAS/ServiNas/Phil Collins - The Singles [1-3]/05 - You Can't Hurry Love.mp3" Jun 17 13:32:28 volumio volumio[835]: info: ControllerMpd::pushState Jun 17 13:32:28 volumio volumio[835]: info: CoreCommandRouter::servicePushState Jun 17 13:32:28 volumio volumio[835]: info: CoreStateMachine::pushState Jun 17 13:32:28 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:32:28 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 17 13:32:28 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Jun 17 13:32:28 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:32:28 volumio volumio[835]: verbose: STATE SERVICE {"status":"stop","position":0,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Thru These Walls","artist":"Phil Collins","album":"The Singles","uri":"NAS/ServiNas/Phil Collins - The Singles [1-3]/04 - Thru These Walls.mp3","trackType":"mp3"} Jun 17 13:32:28 volumio volumio[835]: verbose: CURRENT POSITION 4 Jun 17 13:32:28 volumio volumio[835]: info: CoreStateMachine::syncState stateService stop Jun 17 13:32:28 volumio volumio[835]: info: CoreStateMachine::syncState currentStatus stop Jun 17 13:32:28 volumio volumio[835]: info: CoreStateMachine::pushState Jun 17 13:32:28 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:32:28 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Jun 17 13:32:28 volumio volumio[835]: info: No code Jun 17 13:32:28 volumio volumio[835]: info: CoreStateMachine::pushState Jun 17 13:32:28 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:32:28 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Jun 17 13:32:28 volumio volumio[835]: info: ------------------------------ 253ms Jun 17 13:32:28 volumio volumio[835]: error: updateQueue error: null Jun 17 13:32:28 volumio volumio[835]: info: Jun 17 13:32:28 volumio volumio[835]: ---------------------------- MPD announces system playlist update Jun 17 13:32:28 volumio volumio[835]: info: Ignoring MPD Status Update Jun 17 13:32:28 volumio volumio[835]: info: ------------------------------ 220ms Jun 17 13:32:28 volumio volumio[835]: info: sendMpdCommand add "NAS/ServiNas/Phil Collins - The Singles [1-3]/05 - You Can't Hurry Love.mp3" took 207 milliseconds Jun 17 13:32:28 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand play Jun 17 13:32:28 volumio volumio[835]: info: [ASDebug] CurState: stop PrevState: stop Jun 17 13:32:28 volumio volumio[835]: info: [ASDebug] CurState: stop PrevState: stop Jun 17 13:32:28 volumio volumio[835]: info: [ASDebug] CurState: stop PrevState: stop Jun 17 13:32:28 volumio volumio[835]: info: Jun 17 13:32:28 volumio volumio[835]: ---------------------------- MPD announces state update: player Jun 17 13:32:28 volumio volumio[835]: info: ------------------------------ 237ms Jun 17 13:32:28 volumio volumio[835]: info: sendMpdCommand play took 229 milliseconds Jun 17 13:32:28 volumio volumio[835]: info: ControllerMpd::getState Jun 17 13:32:28 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand status Jun 17 13:32:28 volumio volumio[835]: info: sendMpdCommand status took 7 milliseconds Jun 17 13:32:28 volumio volumio[835]: verbose: ControllerMpd::parseState Jun 17 13:32:28 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 17 13:32:28 volumio volumio[835]: info: sendMpdCommand playlistinfo took 7 milliseconds Jun 17 13:32:28 volumio volumio[835]: verbose: ControllerMpd::parseTrackInfo Jun 17 13:32:28 volumio volumio[835]: info: ControllerMpd::pushState Jun 17 13:32:28 volumio volumio[835]: info: CoreCommandRouter::servicePushState Jun 17 13:32:28 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:32:28 volumio volumio[835]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":178,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"You Can't Hurry Love","artist":"Phil Collins","album":"The Singles","uri":"NAS/ServiNas/Phil Collins - The Singles [1-3]/05 - You Can't Hurry Love.mp3","trackType":"mp3"} Jun 17 13:32:28 volumio volumio[835]: verbose: CURRENT POSITION 4 Jun 17 13:32:28 volumio volumio[835]: info: CoreStateMachine::syncState stateService play Jun 17 13:32:28 volumio volumio[835]: info: CoreStateMachine::syncState currentStatus stop Jun 17 13:32:28 volumio volumio[835]: info: ------------------------------ 95ms Jun 17 13:32:35 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 17 13:32:35 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 17 13:32:35 volumio sshd[1209]: pam_unix(sshd:session): session closed for user volumio Jun 17 13:32:35 volumio systemd-logind[310]: Session 3 logged out. Waiting for processes to exit. Jun 17 13:32:35 volumio systemd[1]: session-3.scope: Succeeded. Jun 17 13:32:35 volumio systemd-logind[310]: Removed session 3. Jun 17 13:32:38 volumio volumio[835]: info: CoreCommandRouter::getUIConfigOnPlugin Jun 17 13:32:38 volumio volumio[835]: info: [ASDebug] Setting UI defaults Jun 17 13:32:38 volumio volumio[835]: info: [ASDebug] Port: 2 Jun 17 13:32:38 volumio volumio[835]: info: [ASDebug] Inverted: true Jun 17 13:32:38 volumio volumio[835]: info: [ASDebug] Latched: false Jun 17 13:32:38 volumio volumio[835]: info: [ASDebug] On pulse width: 500 Jun 17 13:32:38 volumio volumio[835]: info: [ASDebug] Off pulse width: 500 Jun 17 13:32:45 volumio systemd[1]: Stopping User Manager for UID 1000... Jun 17 13:32:45 volumio systemd[1212]: Stopped target Default. Jun 17 13:32:45 volumio systemd[1212]: Stopped target Basic System. Jun 17 13:32:45 volumio systemd[1212]: Stopped target Paths. Jun 17 13:32:45 volumio systemd[1212]: Stopped target Sockets. Jun 17 13:32:45 volumio systemd[1212]: gpg-agent-browser.socket: Succeeded. Jun 17 13:32:45 volumio systemd[1212]: Closed GnuPG cryptographic agent and passphrase cache (access for web browsers). Jun 17 13:32:45 volumio systemd[1212]: pulseaudio.socket: Succeeded. Jun 17 13:32:45 volumio systemd[1212]: Closed Sound System. Jun 17 13:32:45 volumio systemd[1212]: gpg-agent.socket: Succeeded. Jun 17 13:32:45 volumio systemd[1212]: Closed GnuPG cryptographic agent and passphrase cache. Jun 17 13:32:45 volumio systemd[1212]: Stopped target Timers. Jun 17 13:32:45 volumio systemd[1212]: dirmngr.socket: Succeeded. Jun 17 13:32:45 volumio systemd[1212]: Closed GnuPG network certificate management daemon. Jun 17 13:32:45 volumio systemd[1212]: gpg-agent-ssh.socket: Succeeded. Jun 17 13:32:45 volumio systemd[1212]: Closed GnuPG cryptographic agent (ssh-agent emulation). Jun 17 13:32:45 volumio systemd[1212]: gpg-agent-extra.socket: Succeeded. Jun 17 13:32:45 volumio systemd[1212]: Closed GnuPG cryptographic agent and passphrase cache (restricted). Jun 17 13:32:45 volumio systemd[1212]: dbus.socket: Succeeded. Jun 17 13:32:45 volumio systemd[1212]: Closed D-Bus User Message Bus Socket. Jun 17 13:32:45 volumio systemd[1212]: Reached target Shutdown. Jun 17 13:32:45 volumio systemd[1212]: systemd-exit.service: Succeeded. Jun 17 13:32:45 volumio systemd[1212]: Started Exit the Session. Jun 17 13:32:45 volumio systemd[1212]: Reached target Exit the Session. Jun 17 13:32:45 volumio systemd[1]: user@1000.service: Succeeded. Jun 17 13:32:45 volumio systemd[1]: Stopped User Manager for UID 1000. Jun 17 13:32:45 volumio systemd[1]: Stopping User Runtime Directory /run/user/1000... Jun 17 13:32:46 volumio systemd[1]: run-user-1000.mount: Succeeded. Jun 17 13:32:46 volumio systemd[1]: user-runtime-dir@1000.service: Succeeded. Jun 17 13:32:46 volumio systemd[1]: Stopped User Runtime Directory /run/user/1000. Jun 17 13:32:46 volumio systemd[1]: Removed slice User Slice of UID 1000. Jun 17 13:32:46 volumio volumio[835]: info: CALLMETHOD: system_controller ampswitch saveOptions [object Object] Jun 17 13:32:46 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: ampswitch , saveOptions Jun 17 13:32:46 volumio volumio[835]: info: [ASDebug] Saving Settings: Port: 2 Jun 17 13:32:46 volumio volumio[835]: info: [ASDebug] Saving Settings: Inverted: true Jun 17 13:32:46 volumio volumio[835]: info: [ASDebug] Saving Settings: Delay: 100 Jun 17 13:32:46 volumio volumio[835]: info: [ASDebug] Saving Settings: Latched: false Jun 17 13:32:46 volumio volumio[835]: info: [ASDebug] Saving Settings: On Pulse width: 500 Jun 17 13:32:46 volumio volumio[835]: info: [ASDebug] Saving Settings: Off Pulse width: 500 Jun 17 13:32:52 volumio volumio[835]: info: CoreCommandRouter::volumioGetState Jun 17 13:32:52 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:32:54 volumio volumio[835]: info: CoreCommandRouter::volumioPause Jun 17 13:32:54 volumio volumio[835]: info: CoreStateMachine::pause Jun 17 13:32:54 volumio volumio[835]: info: CoreStateMachine::stPlaybackTimer Jun 17 13:32:54 volumio volumio[835]: info: CoreStateMachine::servicePause Jun 17 13:32:54 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:32:54 volumio volumio[835]: info: CoreCommandRouter::servicePause Jun 17 13:32:54 volumio volumio[835]: info: ControllerMpd::pause Jun 17 13:32:54 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand pause Jun 17 13:32:54 volumio volumio[835]: info: Jun 17 13:32:54 volumio volumio[835]: ---------------------------- MPD announces state update: player Jun 17 13:32:54 volumio volumio[835]: info: sendMpdCommand pause took 87 milliseconds Jun 17 13:32:54 volumio volumio[835]: info: ControllerMpd::getState Jun 17 13:32:54 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand status Jun 17 13:32:54 volumio volumio[835]: info: sendMpdCommand status took 4 milliseconds Jun 17 13:32:54 volumio volumio[835]: verbose: ControllerMpd::parseState Jun 17 13:32:54 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 17 13:32:54 volumio volumio[835]: info: sendMpdCommand playlistinfo took 4 milliseconds Jun 17 13:32:54 volumio volumio[835]: verbose: ControllerMpd::parseTrackInfo Jun 17 13:32:54 volumio volumio[835]: info: ControllerMpd::pushState Jun 17 13:32:54 volumio volumio[835]: info: CoreCommandRouter::servicePushState Jun 17 13:32:54 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:32:54 volumio volumio[835]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":26685,"duration":178,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"You Can't Hurry Love","artist":"Phil Collins","album":"The Singles","uri":"NAS/ServiNas/Phil Collins - The Singles [1-3]/05 - You Can't Hurry Love.mp3","trackType":"mp3"} Jun 17 13:32:54 volumio volumio[835]: verbose: CURRENT POSITION 4 Jun 17 13:32:54 volumio volumio[835]: info: CoreStateMachine::syncState stateService pause Jun 17 13:32:54 volumio volumio[835]: info: CoreStateMachine::syncState currentStatus pause Jun 17 13:32:54 volumio volumio[835]: info: CoreStateMachine::pushState Jun 17 13:32:54 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:32:54 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 17 13:32:54 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Jun 17 13:32:54 volumio volumio[835]: info: CoreStateMachine::stPlaybackTimer Jun 17 13:32:54 volumio volumio[835]: info: ------------------------------ 102ms Jun 17 13:32:54 volumio volumio[835]: info: [ASDebug] CurState: pause PrevState: stop Jun 17 13:33:03 volumio sshd[1352]: Accepted password for volumio from 192.168.1.47 port 47468 ssh2 Jun 17 13:33:03 volumio sshd[1352]: pam_unix(sshd:session): session opened for user volumio by (uid=0) Jun 17 13:33:03 volumio systemd[1]: Created slice User Slice of UID 1000. Jun 17 13:33:03 volumio systemd[1]: Starting User Runtime Directory /run/user/1000... Jun 17 13:33:03 volumio systemd-logind[310]: New session 5 of user volumio. Jun 17 13:33:03 volumio systemd[1]: Started User Runtime Directory /run/user/1000. Jun 17 13:33:03 volumio systemd[1]: Starting User Manager for UID 1000... Jun 17 13:33:03 volumio systemd[1355]: pam_unix(systemd-user:session): session opened for user volumio by (uid=0) Jun 17 13:33:04 volumio systemd[1355]: mpd.socket: Failed to create listening socket ([::]:6600): Address already in use Jun 17 13:33:04 volumio systemd[1355]: mpd.socket: Failed to listen on sockets: Address already in use Jun 17 13:33:04 volumio systemd[1355]: mpd.socket: Failed with result 'resources'. Jun 17 13:33:04 volumio systemd[1355]: Failed to listen on mpd.socket. Jun 17 13:33:04 volumio systemd[1355]: Listening on GnuPG cryptographic agent (ssh-agent emulation). Jun 17 13:33:04 volumio systemd[1355]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers). Jun 17 13:33:04 volumio systemd[1355]: Reached target Timers. Jun 17 13:33:04 volumio systemd[1355]: Reached target Paths. Jun 17 13:33:04 volumio systemd[1355]: Listening on GnuPG network certificate management daemon. Jun 17 13:33:04 volumio systemd[1355]: Listening on GnuPG cryptographic agent and passphrase cache (restricted). Jun 17 13:33:04 volumio systemd[1355]: Starting D-Bus User Message Bus Socket. Jun 17 13:33:04 volumio systemd[1355]: Listening on Sound System. Jun 17 13:33:04 volumio systemd[1355]: Listening on GnuPG cryptographic agent and passphrase cache. Jun 17 13:33:04 volumio systemd[1355]: Listening on D-Bus User Message Bus Socket. Jun 17 13:33:04 volumio systemd[1355]: Reached target Sockets. Jun 17 13:33:04 volumio systemd[1355]: Reached target Basic System. Jun 17 13:33:04 volumio systemd[1]: Started User Manager for UID 1000. Jun 17 13:33:04 volumio systemd[1355]: Starting Music Player Daemon... Jun 17 13:33:04 volumio systemd[1]: Started Session 5 of user volumio. Jun 17 13:33:05 volumio sudo[1378]: volumio : TTY=unknown ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/bash -c touch /testsudo.tmp && rm -rf /testsudo.tmp Jun 17 13:33:05 volumio sudo[1378]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:33:05 volumio sudo[1378]: pam_unix(sudo:session): session closed for user root Jun 17 13:33:06 volumio sudo[1383]: volumio : TTY=unknown ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/bash -c if [ -e /sys/class/gpio/gpio26 ] ; then cat /sys/class/gpio/gpio26/direction && cat /sys/class/gpio/gpio26/value ; else tee /sys/class/gpio/export <<< "26" > /dev/null && cat /sys/class/gpio/gpio26/direction && cat /sys/class/gpio/gpio26/value ; fi Jun 17 13:33:06 volumio sudo[1383]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:33:06 volumio sudo[1383]: pam_unix(sudo:session): session closed for user root Jun 17 13:33:08 volumio sudo[1389]: volumio : TTY=unknown ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/bash -c echo in > /sys/class/gpio/gpio26/direction && cat /sys/class/gpio/gpio26/direction && cat /sys/class/gpio/gpio26/value Jun 17 13:33:08 volumio sudo[1389]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:33:08 volumio sudo[1389]: pam_unix(sudo:session): session closed for user root Jun 17 13:33:10 volumio mpd[1366]: Jun 17 13:33 : exception: Failed to bind to '[::]:6600' Jun 17 13:33:10 volumio mpd[1366]: Jun 17 13:33 : exception: nested: Failed to bind socket: Address already in use Jun 17 13:33:10 volumio systemd[1355]: mpd.service: Main process exited, code=exited, status=1/FAILURE Jun 17 13:33:10 volumio systemd[1355]: mpd.service: Failed with result 'exit-code'. Jun 17 13:33:10 volumio systemd[1355]: Failed to start Music Player Daemon. Jun 17 13:33:10 volumio systemd[1355]: Reached target Default. Jun 17 13:33:10 volumio systemd[1355]: Startup finished in 6.649s. Jun 17 13:33:12 volumio sudo[1394]: volumio : TTY=unknown ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/bash -c echo out > /sys/class/gpio/gpio26/direction && cat /sys/class/gpio/gpio26/direction && cat /sys/class/gpio/gpio26/value Jun 17 13:33:12 volumio sudo[1394]: pam_unix(sudo:session): session opened for user root by (uid=0) Jun 17 13:33:13 volumio sudo[1394]: pam_unix(sudo:session): session closed for user root Jun 17 13:33:19 volumio volumio[835]: info: CoreCommandRouter::volumioPlay Jun 17 13:33:19 volumio volumio[835]: info: CoreStateMachine::play index undefined Jun 17 13:33:19 volumio volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Jun 17 13:33:19 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:33:19 volumio volumio[835]: info: CoreStateMachine::startPlaybackTimer Jun 17 13:33:19 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:33:19 volumio volumio[835]: info: ControllerMpd::resume Jun 17 13:33:19 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand play Jun 17 13:33:20 volumio volumio[835]: info: sendMpdCommand play took 78 milliseconds Jun 17 13:33:20 volumio volumio[835]: info: Jun 17 13:33:20 volumio volumio[835]: ---------------------------- MPD announces state update: player Jun 17 13:33:20 volumio volumio[835]: info: ControllerMpd::getState Jun 17 13:33:20 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand status Jun 17 13:33:20 volumio volumio[835]: info: sendMpdCommand status took 20 milliseconds Jun 17 13:33:20 volumio volumio[835]: verbose: ControllerMpd::parseState Jun 17 13:33:20 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 17 13:33:20 volumio volumio[835]: info: sendMpdCommand playlistinfo took 4 milliseconds Jun 17 13:33:20 volumio volumio[835]: verbose: ControllerMpd::parseTrackInfo Jun 17 13:33:20 volumio volumio[835]: info: ControllerMpd::pushState Jun 17 13:33:20 volumio volumio[835]: info: CoreCommandRouter::servicePushState Jun 17 13:33:20 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:33:20 volumio volumio[835]: verbose: STATE SERVICE {"status":"play","position":0,"seek":27577,"duration":178,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"You Can't Hurry Love","artist":"Phil Collins","album":"The Singles","uri":"NAS/ServiNas/Phil Collins - The Singles [1-3]/05 - You Can't Hurry Love.mp3","trackType":"mp3"} Jun 17 13:33:20 volumio volumio[835]: verbose: CURRENT POSITION 4 Jun 17 13:33:20 volumio volumio[835]: info: CoreStateMachine::syncState stateService play Jun 17 13:33:20 volumio volumio[835]: info: CoreStateMachine::syncState currentStatus pause Jun 17 13:33:20 volumio volumio[835]: info: CoreStateMachine::pushState Jun 17 13:33:20 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:33:20 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 17 13:33:20 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Jun 17 13:33:20 volumio volumio[835]: info: ------------------------------ 140ms Jun 17 13:33:20 volumio volumio[835]: info: [ASDebug] CurState: play PrevState: stop Jun 17 13:33:20 volumio volumio[835]: info: [ASDebug] Togle GPIO: ON Jun 17 13:33:25 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Jun 17 13:33:25 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Jun 17 13:33:28 volumio volumio[835]: info: [ASDebug] Port: 2 Jun 17 13:33:28 volumio volumio[835]: info: [ASDebug] Inverted: true Jun 17 13:33:28 volumio volumio[835]: info: [ASDebug] Delay: 100 Jun 17 13:33:32 volumio volumio[835]: info: CoreCommandRouter::volumioPause Jun 17 13:33:32 volumio volumio[835]: info: CoreStateMachine::pause Jun 17 13:33:32 volumio volumio[835]: info: CoreStateMachine::stPlaybackTimer Jun 17 13:33:32 volumio volumio[835]: info: CoreStateMachine::servicePause Jun 17 13:33:32 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:33:32 volumio volumio[835]: info: CoreCommandRouter::servicePause Jun 17 13:33:32 volumio volumio[835]: info: ControllerMpd::pause Jun 17 13:33:32 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand pause Jun 17 13:33:32 volumio volumio[835]: info: Jun 17 13:33:32 volumio volumio[835]: ---------------------------- MPD announces state update: player Jun 17 13:33:32 volumio volumio[835]: info: sendMpdCommand pause took 79 milliseconds Jun 17 13:33:32 volumio volumio[835]: info: ControllerMpd::getState Jun 17 13:33:32 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand status Jun 17 13:33:32 volumio volumio[835]: info: sendMpdCommand status took 4 milliseconds Jun 17 13:33:32 volumio volumio[835]: verbose: ControllerMpd::parseState Jun 17 13:33:32 volumio volumio[835]: verbose: ControllerMpd::sendMpdCommand playlistinfo Jun 17 13:33:32 volumio volumio[835]: info: sendMpdCommand playlistinfo took 4 milliseconds Jun 17 13:33:32 volumio volumio[835]: verbose: ControllerMpd::parseTrackInfo Jun 17 13:33:32 volumio volumio[835]: info: ControllerMpd::pushState Jun 17 13:33:32 volumio volumio[835]: info: CoreCommandRouter::servicePushState Jun 17 13:33:32 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:33:32 volumio volumio[835]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":39679,"duration":178,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"You Can't Hurry Love","artist":"Phil Collins","album":"The Singles","uri":"NAS/ServiNas/Phil Collins - The Singles [1-3]/05 - You Can't Hurry Love.mp3","trackType":"mp3"} Jun 17 13:33:32 volumio volumio[835]: verbose: CURRENT POSITION 4 Jun 17 13:33:32 volumio volumio[835]: info: CoreStateMachine::syncState stateService pause Jun 17 13:33:32 volumio volumio[835]: info: CoreStateMachine::syncState currentStatus pause Jun 17 13:33:32 volumio volumio[835]: info: CoreStateMachine::pushState Jun 17 13:33:32 volumio volumio[835]: info: CorePlayQueue::getTrack 4 Jun 17 13:33:32 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jun 17 13:33:32 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Jun 17 13:33:32 volumio volumio[835]: info: CoreStateMachine::stPlaybackTimer Jun 17 13:33:32 volumio volumio[835]: info: ------------------------------ 103ms Jun 17 13:33:32 volumio volumio[835]: info: [ASDebug] CurState: pause PrevState: play Jun 17 13:33:32 volumio volumio[835]: info: [ASDebug] InitTimeout - Amp off in: 100 ms Jun 17 13:33:32 volumio volumio[835]: info: [ASDebug] Togle GPIO: OFF Jun 17 13:33:32 volumio volumio[835]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 17 13:33:32 volumio volumio[835]: Error: EBADF: bad file descriptor, write Jun 17 13:33:32 volumio volumio[835]: at Object.writeSync (fs.js:711:3) Jun 17 13:33:32 volumio volumio[835]: at Gpio.writeSync (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:243:8) Jun 17 13:33:32 volumio volumio[835]: at AmpSwitchController.off (/data/plugins/system_controller/ampswitch/index.js:223:23) Jun 17 13:33:32 volumio volumio[835]: at Timeout._onTimeout (/data/plugins/system_controller/ampswitch/index.js:195:88) Jun 17 13:33:32 volumio volumio[835]: at listOnTimeout (internal/timers.js:554:17) Jun 17 13:33:32 volumio volumio[835]: at processTimers (internal/timers.js:497:7) { Jun 17 13:33:32 volumio volumio[835]: errno: -9, Jun 17 13:33:32 volumio volumio[835]: syscall: 'write', Jun 17 13:33:32 volumio volumio[835]: code: 'EBADF' Jun 17 13:33:32 volumio volumio[835]: } Jun 17 13:33:32 volumio volumio[835]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jun 17 13:33:34 volumio sudo[1408]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-06-17 13:32 Jun 17 13:33:34 volumio sudo[1408]: 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="893d2e91c55a7857b58762e70c2f65b9d163562b" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="30b77d58bf3c2745acc494ddafed946392a79905" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 20 Oct 2023 03:38:28 PM CEST" VOLUMIO_VERSION="3.569" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4163d3756b55b3bf7c480d7285f68954"