Mar 25 10:44:37 volumio sshd[5349]: pam_unix(sshd:session): session closed for user volumio
Mar 25 10:44:37 volumio systemd[1]: session-1.scope: Deactivated successfully.
Mar 25 10:44:37 volumio systemd-logind[1018]: Session 1 logged out. Waiting for processes to exit.
Mar 25 10:44:37 volumio systemd-logind[1018]: Removed session 1.
Mar 25 10:44:47 volumio systemd[1]: Stopping user@1000.service - User Manager for UID 1000...
Mar 25 10:44:47 volumio systemd[5352]: Activating special unit exit.target...
Mar 25 10:44:47 volumio systemd[5352]: Stopped target default.target - Main User Target.
Mar 25 10:44:47 volumio systemd[5352]: Stopping mpris-proxy.service - Bluetooth mpris proxy...
Mar 25 10:44:47 volumio mpris-proxy[5370]: org.bluez appeared
Mar 25 10:44:47 volumio mpris-proxy[5370]: Bluetooth Adapter /org/bluez/hci0 found
Mar 25 10:44:47 volumio mpris-proxy[5370]: Bluetooth Adapter /org/bluez/hci0 removed
Mar 25 10:44:47 volumio mpris-proxy[5370]: org.bluez disappeared
Mar 25 10:44:47 volumio systemd[5352]: Stopped mpris-proxy.service - Bluetooth mpris proxy.
Mar 25 10:44:47 volumio systemd[5352]: Stopping dbus.service - D-Bus User Message Bus...
Mar 25 10:44:47 volumio systemd[5352]: Stopped dbus.service - D-Bus User Message Bus.
Mar 25 10:44:47 volumio systemd[5352]: Removed slice session.slice - User Core Session Slice.
Mar 25 10:44:47 volumio systemd[5352]: Stopped target basic.target - Basic System.
Mar 25 10:44:47 volumio systemd[5352]: Stopped target paths.target - Paths.
Mar 25 10:44:47 volumio systemd[5352]: Stopped target sockets.target - Sockets.
Mar 25 10:44:47 volumio systemd[5352]: Stopped target timers.target - Timers.
Mar 25 10:44:47 volumio systemd[5352]: Closed dbus.socket - D-Bus User Message Bus Socket.
Mar 25 10:44:47 volumio systemd[5352]: Closed dirmngr.socket - GnuPG network certificate management daemon.
Mar 25 10:44:47 volumio systemd[5352]: Closed gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers).
Mar 25 10:44:47 volumio systemd[5352]: Closed gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted).
Mar 25 10:44:47 volumio systemd[5352]: Closed gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation).
Mar 25 10:44:47 volumio systemd[5352]: Closed gpg-agent.socket - GnuPG cryptographic agent and passphrase cache.
Mar 25 10:44:47 volumio systemd[5352]: Removed slice app.slice - User Application Slice.
Mar 25 10:44:47 volumio systemd[5352]: Reached target shutdown.target - Shutdown.
Mar 25 10:44:47 volumio systemd[5352]: Finished systemd-exit.service - Exit the Session.
Mar 25 10:44:47 volumio systemd[5352]: Reached target exit.target - Exit the Session.
Mar 25 10:44:47 volumio systemd[1]: user@1000.service: Deactivated successfully.
Mar 25 10:44:47 volumio systemd[1]: Stopped user@1000.service - User Manager for UID 1000.
Mar 25 10:44:47 volumio systemd[1]: Stopping user-runtime-dir@1000.service - User Runtime Directory /run/user/1000...
Mar 25 10:44:47 volumio systemd[1]: run-user-1000.mount: Deactivated successfully.
Mar 25 10:44:47 volumio systemd[1]: user-runtime-dir@1000.service: Deactivated successfully.
Mar 25 10:44:47 volumio systemd[1]: Stopped user-runtime-dir@1000.service - User Runtime Directory /run/user/1000.
Mar 25 10:44:47 volumio systemd[1]: Removed slice user-1000.slice - User Slice of UID 1000.
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:07 volumio volumio[1314]: info: Prefetching next song
Mar 25 10:45:07 volumio volumio[1314]: info: DOING PREFETCH IN MPD
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand add "USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac"
Mar 25 10:45:07 volumio volumio[1314]: info:
Mar 25 10:45:07 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:07 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:07 volumio volumio[1314]: info: sendMpdCommand add "USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" took 1 milliseconds
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand consume 1
Mar 25 10:45:07 volumio volumio[1314]: info:
Mar 25 10:45:07 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:07 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:07 volumio volumio[1314]: info:
Mar 25 10:45:07 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:07 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:07 volumio volumio[1314]: info:
Mar 25 10:45:07 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:07 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:07 volumio volumio[1314]: info:
Mar 25 10:45:07 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:07 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:07 volumio volumio[1314]: info:
Mar 25 10:45:07 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:07 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:07 volumio volumio[1314]: info:
Mar 25 10:45:07 volumio volumio[1314]: ---------------------------- MPD announces state update: options
Mar 25 10:45:07 volumio volumio[1314]: info: ------------------------------ 2ms
Mar 25 10:45:07 volumio volumio[1314]: info: sendMpdCommand consume 1 took 2 milliseconds
Mar 25 10:45:07 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:07 volumio volumio[1314]: info: ------------------------------ 2ms
Mar 25 10:45:07 volumio volumio[1314]: info: ------------------------------ 1ms
Mar 25 10:45:07 volumio volumio[1314]: info: ------------------------------ 1ms
Mar 25 10:45:07 volumio volumio[1314]: info: ------------------------------ 1ms
Mar 25 10:45:07 volumio volumio[1314]: info: ------------------------------ 1ms
Mar 25 10:45:07 volumio volumio[1314]: info:
Mar 25 10:45:07 volumio volumio[1314]: ---------------------------- MPD announces state update: options
Mar 25 10:45:07 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:07 volumio volumio[1314]: info:
Mar 25 10:45:07 volumio volumio[1314]: ---------------------------- MPD announces state update: options
Mar 25 10:45:07 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:07 volumio volumio[1314]: info:
Mar 25 10:45:07 volumio volumio[1314]: ---------------------------- MPD announces state update: options
Mar 25 10:45:07 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:07 volumio volumio[1314]: info:
Mar 25 10:45:07 volumio volumio[1314]: ---------------------------- MPD announces state update: options
Mar 25 10:45:07 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:07 volumio volumio[1314]: info:
Mar 25 10:45:07 volumio volumio[1314]: ---------------------------- MPD announces state update: options
Mar 25 10:45:07 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:07 volumio volumio[1314]: info: sendMpdCommand status took 2 milliseconds
Mar 25 10:45:07 volumio volumio[1314]: info: sendMpdCommand status took 1 milliseconds
Mar 25 10:45:07 volumio volumio[1314]: info: sendMpdCommand status took 1 milliseconds
Mar 25 10:45:07 volumio volumio[1314]: info: sendMpdCommand status took 1 milliseconds
Mar 25 10:45:07 volumio volumio[1314]: info: sendMpdCommand status took 1 milliseconds
Mar 25 10:45:07 volumio volumio[1314]: info: sendMpdCommand status took 0 milliseconds
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:07 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 25 10:45:07 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 25 10:45:07 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 25 10:45:07 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 25 10:45:07 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 25 10:45:07 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:07 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:07 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: verbose: STATE SERVICE {"status":"play","position":0,"seek":257151,"duration":262,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"483 Kbps","isStreaming":false,"title":"When I Fall in Love","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac","trackType":"flac"}
Mar 25 10:45:07 volumio volumio[1314]: verbose: CURRENT POSITION 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::syncState stateService play
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus play
Mar 25 10:45:07 volumio volumio[1314]: info: Received an update from plugin. extracting info from payload
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:07 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: verbose: STATE SERVICE {"status":"play","position":0,"seek":257151,"duration":262,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"483 Kbps","isStreaming":false,"title":"When I Fall in Love","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac","trackType":"flac"}
Mar 25 10:45:07 volumio volumio[1314]: verbose: CURRENT POSITION 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::syncState stateService play
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus play
Mar 25 10:45:07 volumio volumio[1314]: info: Received an update from plugin. extracting info from payload
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:07 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: verbose: STATE SERVICE {"status":"play","position":0,"seek":257151,"duration":262,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"483 Kbps","isStreaming":false,"title":"When I Fall in Love","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac","trackType":"flac"}
Mar 25 10:45:07 volumio volumio[1314]: verbose: CURRENT POSITION 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::syncState stateService play
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus play
Mar 25 10:45:07 volumio volumio[1314]: info: Received an update from plugin. extracting info from payload
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:07 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: verbose: STATE SERVICE {"status":"play","position":0,"seek":257151,"duration":262,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"483 Kbps","isStreaming":false,"title":"When I Fall in Love","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac","trackType":"flac"}
Mar 25 10:45:07 volumio volumio[1314]: verbose: CURRENT POSITION 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::syncState stateService play
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus play
Mar 25 10:45:07 volumio volumio[1314]: info: Received an update from plugin. extracting info from payload
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:07 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: verbose: STATE SERVICE {"status":"play","position":0,"seek":257151,"duration":262,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"483 Kbps","isStreaming":false,"title":"When I Fall in Love","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac","trackType":"flac"}
Mar 25 10:45:07 volumio volumio[1314]: verbose: CURRENT POSITION 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::syncState stateService play
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus play
Mar 25 10:45:07 volumio volumio[1314]: info: Received an update from plugin. extracting info from payload
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:07 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: verbose: STATE SERVICE {"status":"play","position":0,"seek":257151,"duration":262,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"483 Kbps","isStreaming":false,"title":"When I Fall in Love","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac","trackType":"flac"}
Mar 25 10:45:07 volumio volumio[1314]: verbose: CURRENT POSITION 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::syncState stateService play
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus play
Mar 25 10:45:07 volumio volumio[1314]: info: Received an update from plugin. extracting info from payload
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:07 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:07 volumio volumio[1314]: info: CorePlayQueue::getTrack 0
Mar 25 10:45:07 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.372+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=257033 volume=100
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.372+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac" title="When I Fall in Love"
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.372+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=257033 volume=100
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.372+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac" title="When I Fall in Love"
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.373+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=257033 volume=100
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.373+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac" title="When I Fall in Love"
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.374+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=257033 volume=100
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.374+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac" title="When I Fall in Love"
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.375+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=257033 volume=100
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.375+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac" title="When I Fall in Love"
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.375+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=257033 volume=100
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.375+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac" title="When I Fall in Love"
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.376+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=257033 volume=100
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.376+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac" title="When I Fall in Love"
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.377+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=257033 volume=100
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.377+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac" title="When I Fall in Love"
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.378+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=257033 volume=100
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.378+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac" title="When I Fall in Love"
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.378+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=257033 volume=100
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.378+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac" title="When I Fall in Love"
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.379+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=257033 volume=100
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.379+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac" title="When I Fall in Love"
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.379+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=257033 volume=100
Mar 25 10:45:07 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:07.380+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/01. When I Fall in Love.flac" title="When I Fall in Love"
Mar 25 10:45:07 volumio volumio[1314]: info: ------------------------------ 74ms
Mar 25 10:45:07 volumio volumio[1314]: info: ------------------------------ 73ms
Mar 25 10:45:07 volumio volumio[1314]: info: ------------------------------ 73ms
Mar 25 10:45:07 volumio volumio[1314]: info: ------------------------------ 73ms
Mar 25 10:45:07 volumio volumio[1314]: info: ------------------------------ 73ms
Mar 25 10:45:07 volumio volumio[1314]: info: ------------------------------ 73ms
Mar 25 10:45:07 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:07 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:07 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:07 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:07 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:07 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:07 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:07 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:07 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:07 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:07 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:07 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:11 volumio volumio[1314]: info: CoreStateMachine::startPlaybackTimer
Mar 25 10:45:11 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.351+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=501 volume=100
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.351+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:12 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:12 volumio volumio[1314]: info:
Mar 25 10:45:12 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:12 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:12 volumio volumio[1314]: info:
Mar 25 10:45:12 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:12 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:12 volumio volumio[1314]: info:
Mar 25 10:45:12 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:12 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:12 volumio volumio[1314]: info:
Mar 25 10:45:12 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:12 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:12 volumio volumio[1314]: info:
Mar 25 10:45:12 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:12 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:12 volumio volumio[1314]: info:
Mar 25 10:45:12 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:12 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:12 volumio volumio[1314]: info:
Mar 25 10:45:12 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:12 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:12 volumio volumio[1314]: info:
Mar 25 10:45:12 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:12 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:12 volumio volumio[1314]: info:
Mar 25 10:45:12 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:12 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:12 volumio volumio[1314]: info:
Mar 25 10:45:12 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:12 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:12 volumio volumio[1314]: info:
Mar 25 10:45:12 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:12 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:12 volumio volumio[1314]: info:
Mar 25 10:45:12 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:12 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:12 volumio volumio[1314]: info: ------------------------------ 3ms
Mar 25 10:45:12 volumio volumio[1314]: info: sendMpdCommand status took 3 milliseconds
Mar 25 10:45:12 volumio volumio[1314]: info: ------------------------------ 3ms
Mar 25 10:45:12 volumio volumio[1314]: info: sendMpdCommand status took 3 milliseconds
Mar 25 10:45:12 volumio volumio[1314]: info: ------------------------------ 2ms
Mar 25 10:45:12 volumio volumio[1314]: info: sendMpdCommand status took 2 milliseconds
Mar 25 10:45:12 volumio volumio[1314]: info: ------------------------------ 2ms
Mar 25 10:45:12 volumio volumio[1314]: info: sendMpdCommand status took 2 milliseconds
Mar 25 10:45:12 volumio volumio[1314]: info: ------------------------------ 1ms
Mar 25 10:45:12 volumio volumio[1314]: info: sendMpdCommand status took 1 milliseconds
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:12 volumio volumio[1314]: info: ------------------------------ 3ms
Mar 25 10:45:12 volumio volumio[1314]: info: sendMpdCommand status took 3 milliseconds
Mar 25 10:45:12 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 2 milliseconds
Mar 25 10:45:12 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 2 milliseconds
Mar 25 10:45:12 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 3 milliseconds
Mar 25 10:45:12 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 3 milliseconds
Mar 25 10:45:12 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 3 milliseconds
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:12 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":310,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"624 Kbps","isStreaming":false,"title":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:12 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::syncState stateService play
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus play
Mar 25 10:45:12 volumio volumio[1314]: info: Received an update from plugin. extracting info from payload
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:12 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":310,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"624 Kbps","isStreaming":false,"title":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:12 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::syncState stateService play
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus play
Mar 25 10:45:12 volumio volumio[1314]: info: Received an update from plugin. extracting info from payload
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:12 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":310,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"624 Kbps","isStreaming":false,"title":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:12 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::syncState stateService play
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus play
Mar 25 10:45:12 volumio volumio[1314]: info: Received an update from plugin. extracting info from payload
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:12 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":310,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"624 Kbps","isStreaming":false,"title":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:12 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::syncState stateService play
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus play
Mar 25 10:45:12 volumio volumio[1314]: info: Received an update from plugin. extracting info from payload
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:12 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":310,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"624 Kbps","isStreaming":false,"title":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:12 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::syncState stateService play
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus play
Mar 25 10:45:12 volumio volumio[1314]: info: Received an update from plugin. extracting info from payload
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.411+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=68 volume=100
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.411+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.411+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=68 volume=100
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.411+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.412+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=68 volume=100
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.412+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.412+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=68 volume=100
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.412+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.413+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=68 volume=100
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.413+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.413+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=68 volume=100
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.413+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.414+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=68 volume=100
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.414+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.414+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=68 volume=100
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.414+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.414+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=68 volume=100
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.414+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.415+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=68 volume=100
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.415+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:12 volumio volumio[1314]: info: ------------------------------ 57ms
Mar 25 10:45:12 volumio volumio[1314]: info: ------------------------------ 57ms
Mar 25 10:45:12 volumio volumio[1314]: info: ------------------------------ 57ms
Mar 25 10:45:12 volumio volumio[1314]: info: ------------------------------ 57ms
Mar 25 10:45:12 volumio volumio[1314]: info: ------------------------------ 56ms
Mar 25 10:45:12 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 53 milliseconds
Mar 25 10:45:12 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:12 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: verbose: STATE SERVICE {"status":"play","position":0,"seek":68,"duration":310,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"624 Kbps","isStreaming":false,"title":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:12 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::syncState stateService play
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus play
Mar 25 10:45:12 volumio volumio[1314]: info: Received an update from plugin. extracting info from payload
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:12 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:12 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:12 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.449+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=68 volume=100
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.449+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.450+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=68 volume=100
Mar 25 10:45:12 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:12.450+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:12 volumio volumio[1314]: info: ------------------------------ 66ms
Mar 25 10:45:12 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:12 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:12 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:12 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:12 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:12 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:12 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:12 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:12 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:12 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:12 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:12 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false
Mar 25 10:45:13 volumio squeezeboxserver[2264]: [10:45:13.009] mDNSsearchCallback:688 [0x195a88]: changed ip:port 192.168.219.105:5000
Mar 25 10:45:14 volumio volumio[1314]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: unknown Engine version: 4 Transport: websocket Total Clients: 9
Mar 25 10:45:14 volumio volumio[1314]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: unknown Engine version: 4 Transport: websocket Total Clients: 9
Mar 25 10:45:14 volumio volumio[1314]: info: CoreCommandRouter::volumioGetState
Mar 25 10:45:14 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:14 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback
Mar 25 10:45:14 volumio volumio[1314]: info: CoreCommandRouter::volumioGetQueue
Mar 25 10:45:14 volumio volumio[1314]: info: CoreStateMachine::getQueue
Mar 25 10:45:14 volumio volumio[1314]: info: CorePlayQueue::getQueue
Mar 25 10:45:17 volumio volumio[1314]: info: CoreCommandRouter::volumioPause
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::pause
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::stPlaybackTimer
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::servicePause
Mar 25 10:45:17 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:17 volumio volumio[1314]: info: CoreCommandRouter::servicePause
Mar 25 10:45:17 volumio volumio[1314]: info: ControllerMpd::pause
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand pause
Mar 25 10:45:17 volumio volumio[1314]: info:
Mar 25 10:45:17 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:17 volumio volumio[1314]: info: sendMpdCommand pause took 2 milliseconds
Mar 25 10:45:17 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:17 volumio volumio[1314]: info:
Mar 25 10:45:17 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:17 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:17 volumio volumio[1314]: info:
Mar 25 10:45:17 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:17 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:17 volumio volumio[1314]: info:
Mar 25 10:45:17 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:17 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:17 volumio volumio[1314]: info:
Mar 25 10:45:17 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:17 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:17 volumio volumio[1314]: info:
Mar 25 10:45:17 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:17 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:17 volumio volumio[1314]: info: sendMpdCommand status took 1 milliseconds
Mar 25 10:45:17 volumio volumio[1314]: info: sendMpdCommand status took 1 milliseconds
Mar 25 10:45:17 volumio volumio[1314]: info: sendMpdCommand status took 1 milliseconds
Mar 25 10:45:17 volumio volumio[1314]: info: sendMpdCommand status took 1 milliseconds
Mar 25 10:45:17 volumio volumio[1314]: info: sendMpdCommand status took 0 milliseconds
Mar 25 10:45:17 volumio volumio[1314]: info: sendMpdCommand status took 0 milliseconds
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:17 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 25 10:45:17 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 2 milliseconds
Mar 25 10:45:17 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 25 10:45:17 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 25 10:45:17 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 25 10:45:17 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:17 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:17 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:17 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:17 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:17 volumio volumio[1314]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5249,"duration":310,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"679 Kbps","isStreaming":false,"title":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:17 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::syncState stateService pause
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus pause
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:17 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:17 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 25 10:45:17 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::stPlaybackTimer
Mar 25 10:45:17 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:17 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:17 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:17 volumio volumio[1314]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5249,"duration":310,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"679 Kbps","isStreaming":false,"title":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:17 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::syncState stateService pause
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus pause
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:17 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:17 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::stPlaybackTimer
Mar 25 10:45:17 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:17 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:17 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:17 volumio volumio[1314]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5249,"duration":310,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"679 Kbps","isStreaming":false,"title":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:17 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::syncState stateService pause
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus pause
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:17 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:17 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::stPlaybackTimer
Mar 25 10:45:17 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:17 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:17 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:17 volumio volumio[1314]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5249,"duration":310,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"679 Kbps","isStreaming":false,"title":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:17 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::syncState stateService pause
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus pause
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:17 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:17 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::stPlaybackTimer
Mar 25 10:45:17 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:17 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:17 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:17 volumio volumio[1314]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5249,"duration":310,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"679 Kbps","isStreaming":false,"title":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:17 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::syncState stateService pause
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus pause
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:17 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:17 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::stPlaybackTimer
Mar 25 10:45:17 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:17 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:17 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:17 volumio volumio[1314]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":5249,"duration":310,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"679 Kbps","isStreaming":false,"title":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:17 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::syncState stateService pause
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus pause
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:17 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:17 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:17 volumio volumio[1314]: info: CoreStateMachine::stPlaybackTimer
Mar 25 10:45:17 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:17.629+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PAUSED positionMs=5322 volume=100
Mar 25 10:45:17 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:17.629+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:17 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:17.629+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PAUSED positionMs=5322 volume=100
Mar 25 10:45:17 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:17.629+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:17 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:17.629+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PAUSED positionMs=5322 volume=100
Mar 25 10:45:17 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:17.630+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:17 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:17.630+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PAUSED positionMs=5322 volume=100
Mar 25 10:45:17 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:17.631+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PAUSED positionMs=5322 volume=100
Mar 25 10:45:17 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:17.632+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:17 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:17.632+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:17 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:17.632+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PAUSED positionMs=5322 volume=100
Mar 25 10:45:17 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:17.632+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:17 volumio volumio[1314]: info: ------------------------------ 43ms
Mar 25 10:45:17 volumio volumio[1314]: info: ------------------------------ 42ms
Mar 25 10:45:17 volumio volumio[1314]: info: ------------------------------ 42ms
Mar 25 10:45:17 volumio volumio[1314]: info: ------------------------------ 42ms
Mar 25 10:45:17 volumio volumio[1314]: info: ------------------------------ 42ms
Mar 25 10:45:17 volumio volumio[1314]: info: ------------------------------ 41ms
Mar 25 10:45:17 volumio volumio[1314]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false
Mar 25 10:45:17 volumio volumio[1314]: info: peppy_screensaver: Starting persist timer - 30s
Mar 25 10:45:17 volumio volumio[1314]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false
Mar 25 10:45:17 volumio volumio[1314]: info: peppy_screensaver: Starting persist timer - 30s
Mar 25 10:45:17 volumio volumio[1314]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false
Mar 25 10:45:17 volumio volumio[1314]: info: peppy_screensaver: Starting persist timer - 30s
Mar 25 10:45:17 volumio volumio[1314]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false
Mar 25 10:45:17 volumio volumio[1314]: info: peppy_screensaver: Starting persist timer - 30s
Mar 25 10:45:17 volumio volumio[1314]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false
Mar 25 10:45:17 volumio volumio[1314]: info: peppy_screensaver: Starting persist timer - 30s
Mar 25 10:45:17 volumio volumio[1314]: info: peppy_screensaver: pushState - status=pause service=mpd volatile=false
Mar 25 10:45:17 volumio volumio[1314]: info: peppy_screensaver: Starting persist timer - 30s
Mar 25 10:45:17 volumio volumio[1314]: info: touch_display: Setting screensaver timeout to 0 seconds.
Mar 25 10:45:19 volumio volumio[1314]: info: Enabling plugin dark_ascendants
Mar 25 10:45:19 volumio volumio[1314]: info: Loading plugin "dark_ascendants"...
Mar 25 10:45:19 volumio volumio[1314]: info: PLUGIN START: dark_ascendants
Mar 25 10:45:19 volumio volumio[1314]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Mar 25 10:45:19 volumio volumio[1314]: info: [1774403119363] CoreMusicLibrary::Adding element Dark Ascendants
Mar 25 10:45:19 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 25 10:45:19 volumio volumio[1314]: Cannot find translation for source 스트리밍 라디오
Mar 25 10:45:19 volumio volumio[1314]: Cannot find translation for source Dark Ascendants
Mar 25 10:45:19 volumio volumio[1314]: info: Done.
Mar 25 10:45:19 volumio volumio[1314]: info: [DarkAscendants] Token restored (refreshed)
Mar 25 10:45:20 volumio volumio[1314]: info: [DarkAscendants] Monochrome Connected: https://eu-central.monochrome.tf
Mar 25 10:45:21 volumio volumio[1314]: info: CoreCommandRouter::getUIConfigOnPlugin
Mar 25 10:45:27 volumio volumio[1314]: info: CoreCommandRouter::volumioGetState
Mar 25 10:45:27 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:27 volumio volumio[1314]: info: CoreCommandRouter::volumioGetQueue
Mar 25 10:45:27 volumio volumio[1314]: info: CoreStateMachine::getQueue
Mar 25 10:45:27 volumio volumio[1314]: info: CorePlayQueue::getQueue
Mar 25 10:45:30 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: dark_ascendants , handleBrowseUri
Mar 25 10:45:30 volumio volumio[1314]: info: [DarkAscendants] handleBrowseUri: darkascendants
Mar 25 10:45:31 volumio volumio[1314]: info: Preload queue cleared
Mar 25 10:45:31 volumio volumio[1314]: info: Preload queue cleared
Mar 25 10:45:31 volumio volumio[1314]: info: Preload queue cleared
Mar 25 10:45:31 volumio volumio[1314]: info: Preload queue cleared
Mar 25 10:45:31 volumio volumio[1314]: info: Preload queue cleared
Mar 25 10:45:31 volumio volumio[1314]: info: Preload queue cleared
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/258407553
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/227734500
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/248051329
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/217164679
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/252777997
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/258407555
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/216929729
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/248051336
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/223358660
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/248711125
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/36336294
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/33695188
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/68732464
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/57638936
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/491622454
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/90822279
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/30349437
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/461233361
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/196435445
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/693991
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/489643491
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/68732390
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/33695189
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/82883
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/43725535
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/111054070
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/94568893
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/95977597
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/96859980
Mar 25 10:45:31 volumio volumio[1314]: info: Preloading song: darkascendants/track/85314658
Mar 25 10:45:31 volumio volumio[1314]: info: Preload queue cleared
Mar 25 10:45:35 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: dark_ascendants , handleBrowseUri
Mar 25 10:45:35 volumio volumio[1314]: info: [DarkAscendants] handleBrowseUri: darkascendants/playlist/0003a4dcb463951b3243a6e759898c
Mar 25 10:45:37 volumio volumio[1314]: info: Preload queue cleared
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77609730
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/53736425
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1610219
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/10843701
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77609732
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/145728300
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/35655263
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77618477
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1610220
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/2902872
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/279977
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77609731
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/35494749
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/188224043
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77618475
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/2044474
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1610224
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/147294
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/94441603
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/279979
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77609812
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1741462
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/285033
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1381749
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77618476
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1779523
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1610223
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/2809492
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/147299
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/94414779
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77698548
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/210553
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1381746
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1286684
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77609733
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/281615
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/19809578
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77648055
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1610225
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77650977
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/147293
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/3764856
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1381745
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/158154
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1320582
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/285190
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/94441973
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/93429450
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77698646
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/285042
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1779522
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/3648159
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1127368
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/188976839
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/163595
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1320692
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/285189
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/158280
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77648060
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/93058765
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/47211056
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/93709600
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/54180482
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/4508204
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/3968167
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/156357
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77623374
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77691394
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77685996
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/108022779
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/149304
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/93539847
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77701376
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/2178497
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77623372
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1330322
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/92096926
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77685995
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/99351701
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/145962473
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77660977
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1294696
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77650864
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/114109142
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/79237477
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/331145
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/3339188
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/42783378
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77623371
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77610694
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77701225
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/77623370
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1461676
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/1461672
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/218872
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/207585
Mar 25 10:45:37 volumio volumio[1314]: info: Preloading song: darkascendants/track/154620413
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/77609730 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/53736425 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/1610219 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/10843701 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/77609732 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/145728300 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/35655263 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/77618477 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/1610220 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/2902872 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/279977 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/77609731 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/35494749 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/188224043 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/77618475 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/2044474 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/1610224 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/147294 in service dark_ascendants
Mar 25 10:45:37 volumio volumio[1314]: info: Exploding uri darkascendants/track/94441603 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/279979 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/77609812 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/1741462 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/285033 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/1381749 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/77618476 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/1779523 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/1610223 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/2809492 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/147299 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/94414779 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/77698548 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/210553 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/1381746 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/1286684 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/77609733 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/281615 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/19809578 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/77648055 in service dark_ascendants
Mar 25 10:45:38 volumio volumio[1314]: info: Exploding uri darkascendants/track/1610225 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/77650977 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/147293 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/3764856 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/1381745 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/158154 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/1320582 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/285190 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/94441973 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/93429450 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/77698646 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/285042 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/1779522 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/3648159 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/1127368 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/188976839 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/163595 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/1320692 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/285189 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/158280 in service dark_ascendants
Mar 25 10:45:39 volumio volumio[1314]: info: Exploding uri darkascendants/track/77648060 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/93058765 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/47211056 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/93709600 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/54180482 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/4508204 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/3968167 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/156357 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/77623374 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/77691394 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/77685996 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/108022779 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/149304 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/93539847 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/77701376 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/2178497 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/77623372 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/1330322 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/92096926 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/77685995 in service dark_ascendants
Mar 25 10:45:40 volumio volumio[1314]: info: Exploding uri darkascendants/track/99351701 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/145962473 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/77660977 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/1294696 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/77650864 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/114109142 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/79237477 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/331145 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/3339188 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/42783378 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/77623371 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/77610694 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/77701225 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/77623370 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: error: [DarkAscendants] explodeUri track: getTrackMeta 42783378 HTTP 404
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/1461676 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/1461672 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/218872 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/207585 in service dark_ascendants
Mar 25 10:45:41 volumio volumio[1314]: info: Exploding uri darkascendants/track/154620413 in service dark_ascendants
Mar 25 10:45:45 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: dark_ascendants , handleBrowseUri
Mar 25 10:45:45 volumio volumio[1314]: info: [DarkAscendants] handleBrowseUri: darkascendants/playlist/00204c9b0897ab9032ef2cd26b2a80
Mar 25 10:45:46 volumio volumio[1314]: info: Preload queue cleared
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/3974254
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/132184655
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/31759874
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/1713342
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/315163624
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/97190472
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/3974261
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/13369587
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/84779515
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/168100637
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/315163629
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/77637380
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/151200339
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/3974259
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/77622761
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/13342776
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/321522029
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/134186880
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/140544815
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/315163617
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/77621909
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/487948537
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/247473040
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/77622841
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/321522018
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/77623271
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/13193509
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/390757142
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/64011694
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/196453694
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/347041546
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/13369579
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/77623346
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/267676266
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/153115657
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/104175162
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/68586446
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/82250316
Mar 25 10:45:46 volumio volumio[1314]: info: Preloading song: darkascendants/track/321522023
Mar 25 10:45:46 volumio volumio[1314]: info: Exploding uri darkascendants/track/3974254 in service dark_ascendants
Mar 25 10:45:46 volumio volumio[1314]: info: Exploding uri darkascendants/track/132184655 in service dark_ascendants
Mar 25 10:45:46 volumio volumio[1314]: info: Exploding uri darkascendants/track/31759874 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/1713342 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Preload queue cleared
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioReplaceandPlayItems
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::ClearQueue
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::stop
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::updateTrackBlock
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrackBlock
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::stPlaybackTimer
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::serviceStop
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::serviceStop
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::stop
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand stop
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::clearPlayQueue
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::saveQueue
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushQueue
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::addQueueItems
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::addQueueItems
Mar 25 10:45:47 volumio volumio[1314]: info: Preload queue cleared
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/3974254
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/3974254 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/132184655
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/132184655 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/31759874
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/31759874 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/1713342
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/1713342 in service dark_ascendants
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.041+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.041+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id="mnt/USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac" title="What'll I Do?"
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: Starting persist timer - 30s
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand stop took 17 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand status took 2 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand status took 1 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand status took 1 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand status took 3 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand status took 3 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand status took 2 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::parseState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: 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":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:47 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::syncState stateService stop
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus stop
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: No code
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: 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":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:47 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::syncState stateService stop
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus stop
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: No code
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: 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":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:47 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::syncState stateService stop
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus stop
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: No code
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.076+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.076+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.077+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.077+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.077+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.077+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.077+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.077+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.078+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.078+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.076+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.078+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.078+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.079+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.079+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.079+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.079+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.079+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 37ms
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 37ms
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 36ms
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 35 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 34 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand playlistinfo took 35 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::parseTrackInfo
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: 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":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:47 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::syncState stateService stop
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus stop
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: No code
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: 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":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:47 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::syncState stateService stop
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus stop
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: No code
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: 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":"What'll I Do?","artist":"Chris Botti","album":"When I Fall In Love","uri":"USB/MQA/Chris Botti/2004 When I Fall In Love [M]/02. What'll I Do-.flac","trackType":"flac"}
Mar 25 10:45:47 volumio volumio[1314]: verbose: CURRENT POSITION 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::syncState stateService stop
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus stop
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: No code
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 1
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.123+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.123+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.123+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.123+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.123+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.123+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.123+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.123+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.126+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.126+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.126+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.126+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.126+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.127+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.127+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.127+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_STOPPED positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.127+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.127+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id= title=
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 84ms
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 84ms
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 83ms
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState: transitional stop (volatile=undefined, getEmptyState), cleared persist file
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushQueue
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::saveQueue
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::updateTrackBlock
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrackBlock
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPlay
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::play index 3
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::addQueueItems
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::addQueueItems
Mar 25 10:45:47 volumio volumio[1314]: info: Preload queue cleared
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/315163624
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/315163624 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/97190472
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/97190472 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/3974261
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/3974261 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/13369587
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/13369587 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/84779515
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/84779515 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/168100637
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/168100637 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/315163629
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/315163629 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/77637380
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/77637380 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/151200339
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/151200339 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/3974259
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/3974259 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/77622761
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/77622761 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/13342776
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/13342776 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/321522029
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/321522029 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/134186880
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/134186880 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/140544815
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/140544815 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/315163617
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/315163617 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/77621909
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/77621909 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/487948537
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/487948537 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/247473040
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/247473040 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/77622841
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/77622841 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/321522018
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/321522018 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/77623271
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/77623271 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/13193509
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/13193509 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/390757142
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/390757142 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/64011694
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/64011694 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/196453694
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/196453694 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/347041546
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/347041546 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/13369579
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/13369579 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/77623346
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/77623346 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/267676266
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/267676266 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/153115657
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/153115657 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/104175162
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/104175162 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/68586446
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/68586446 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/82250316
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/82250316 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/321522023
Mar 25 10:45:47 volumio volumio[1314]: info: Exploding uri darkascendants/track/321522023 in service dark_ascendants
Mar 25 10:45:47 volumio volumio[1314]: info: Adding Item to queue: darkascendants/track/10843701
Mar 25 10:45:47 volumio volumio[1314]: info: Using cached record of: darkascendants/track/10843701
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::stop
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::play index undefined
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::setConsumeUpdateService undefined
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 3
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::startPlaybackTimer
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 3
Mar 25 10:45:47 volumio volumio[1314]: info: [DarkAscendants] clearAddPlayTrack quality=HI_RES_LOSSLESS useHiResProxy=true raw=true
Mar 25 10:45:47 volumio volumio[1314]: info: [DarkAscendants] clearAddPlayTrack: darkascendants/track/1713342
Mar 25 10:45:47 volumio volumio[1314]: info: [TidalApi] getStreamUrl[HI_RES_LOSSLESS] trackId=1713342 audioQuality=LOSSLESS mimeType=application/vnd.tidal.bts encType=NONE api.bitDepth=16 api.sampleRate=44100
Mar 25 10:45:47 volumio volumio[1314]: info: [TidalApi] getStreamUrl OK(BTS): quality=LOSSLESS bitDepth=16 sampleRate=44100 bts.bitDepth=undefined bts.sampleRate=undefined
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 3
Mar 25 10:45:47 volumio volumio[1314]: verbose: STATE SERVICE {"status":"play","service":"dark_ascendants","uri":"darkascendants/track/1713342","name":"Speak Low","title":"Speak Low","artist":"Roy Hargrove","album":"Earfood","albumart":"https://resources.tidal.com/images/ba66a65a/ecfd/4f4b/af0b/dcd92dcabdaa/1280x1280.jpg","duration":317,"samplerate":"44.1 kHz","bitdepth":"16 bit","trackType":"flac","channels":2,"seek":0}
Mar 25 10:45:47 volumio volumio[1314]: verbose: CURRENT POSITION 3
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::syncState stateService play
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus stop
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand stop
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand stop took 1 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand clear
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand clear took 0 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand add "https://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiRhNDdkMDQ1MGRkNGUzYzczMDU1NDk2ZDM3NDRkOGI0MS5tcDQ/0.flac?token=1774406747~OWYzMjJjOTlmNTgzYmY1ZjJlYmYwZTAwYzg3NTZiNjU5ODlmMTJkMg=="
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:47 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:47 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:47 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:47 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:47 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:47 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:47 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand add "https://lgf.audio.tidal.com/mediatracks/CAEaKAgDEiRhNDdkMDQ1MGRkNGUzYzczMDU1NDk2ZDM3NDRkOGI0MS5tcDQ/0.flac?token=1774406747~OWYzMjJjOTlmNTgzYmY1ZjJlYmYwZTAwYzg3NTZiNjU5ODlmMTJkMg==" took 2 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 2ms
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 1ms
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 1ms
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 1ms
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 1ms
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 1ms
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand play
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:47 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:47 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:47 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:47 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces system playlist update
Mar 25 10:45:47 volumio volumio[1314]: info: Ignoring MPD Status Update
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 2ms
Mar 25 10:45:47 volumio volumio[1314]: info: sendMpdCommand play took 1 milliseconds
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 1ms
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 1ms
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 1ms
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 0ms
Mar 25 10:45:47 volumio volumio[1314]: info: ------------------------------ 0ms
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 3
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::servicePushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 3
Mar 25 10:45:47 volumio volumio[1314]: verbose: STATE SERVICE {"status":"play","service":"dark_ascendants","uri":"darkascendants/track/1713342","name":"Speak Low","title":"Speak Low","artist":"Roy Hargrove","album":"Earfood","albumart":"https://resources.tidal.com/images/ba66a65a/ecfd/4f4b/af0b/dcd92dcabdaa/1280x1280.jpg","duration":317,"samplerate":"44.1 kHz","bitdepth":"16 bit","trackType":"flac","channels":2,"seek":0}
Mar 25 10:45:47 volumio volumio[1314]: verbose: CURRENT POSITION 3
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::syncState stateService play
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::syncState currentStatus play
Mar 25 10:45:47 volumio volumio[1314]: info: Received an update from plugin. extracting info from payload
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 3
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio[1314]: info: CoreStateMachine::pushState
Mar 25 10:45:47 volumio volumio[1314]: info: CorePlayQueue::getTrack 3
Mar 25 10:45:47 volumio volumio[1314]: info: CoreCommandRouter::volumioPushState
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.720+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.720+09:00 level=INFO msg="emitting player state changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" state=STATUS_PLAYING positionMs=0 volume=100
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.720+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id=darkascendants/track/1713342 title="Speak Low"
Mar 25 10:45:47 volumio volumio5-onboarding[3128]: time=2026-03-25T10:45:47.720+09:00 level=INFO msg="emitting player metadata changed event" component=server peer="192.168.219.119:52296 @ 0x1400f60" id=darkascendants/track/1713342 title="Speak Low"
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=dark_ascendants volatile=false
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: Persist timer cancelled - playback resumed
Mar 25 10:45:47 volumio volumio[1314]: info: peppy_screensaver: pushState - status=play service=dark_ascendants volatile=false
Mar 25 10:45:47 volumio volumio[1314]: info: touch_display: Setting screensaver timeout to 0 seconds.
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:47 volumio volumio[1314]: info:
Mar 25 10:45:47 volumio volumio[1314]: ---------------------------- MPD announces state update: player
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:47 volumio volumio[1314]: info: ControllerMpd::getState
Mar 25 10:45:47 volumio volumio[1314]: verbose: ControllerMpd::sendMpdCommand status
Mar 25 10:45:47 volumio volumio[1314]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 25 10:45:47 volumio volumio[1314]: TypeError: self.mpdPlugin.getState(...).then(...).catch is not a function
Mar 25 10:45:47 volumio volumio[1314]: at self._onMpdPlayer (/data/plugins/music_service/dark_ascendants/index.js:167:13)
Mar 25 10:45:47 volumio volumio[1314]: at MpdClient.emit (node:events:514:28)
Mar 25 10:45:47 volumio volumio[1314]: at /volumio/app/plugins/music_service/mpd/lib/mpd.js:128:12
Mar 25 10:45:47 volumio volumio[1314]: at Array.forEach ()
Mar 25 10:45:47 volumio volumio[1314]: at MpdClient.handleIdleResults (/volumio/app/plugins/music_service/mpd/lib/mpd.js:125:19)
Mar 25 10:45:47 volumio volumio[1314]: at MpdClient.handleIdleResultsLoop (/volumio/app/plugins/music_service/mpd/lib/mpd.js:115:8)
Mar 25 10:45:47 volumio volumio[1314]: at /volumio/app/plugins/music_service/mpd/lib/mpd.js:97:12
Mar 25 10:45:47 volumio volumio[1314]: at MpdClient.handleMessage (/volumio/app/plugins/music_service/mpd/lib/mpd.js:77:3)
Mar 25 10:45:47 volumio volumio[1314]: at MpdClient.receive (/volumio/app/plugins/music_service/mpd/lib/mpd.js:68:12)
Mar 25 10:45:47 volumio volumio[1314]: at Socket. (/volumio/app/plugins/music_service/mpd/lib/mpd.js:43:12)
Mar 25 10:45:47 volumio volumio[1314]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 25 10:45:48 volumio sudo[5927]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-25 10:44'
Mar 25 10:45:48 volumio sudo[5927]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="dc61260dec5515dafd2b634881860b4c46c919ff"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri Mar 6 16:46:58 UTC 2026"
VOLUMIO_VERSION="4.103"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="aa741395b8bfc648ff5d04e312f53d2c"