-- Logs begin at Thu 2019-02-14 18:11:58 CST, end at Sun 2025-05-11 00:01:57 CST. -- May 11 00:00:01 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 11 00:00:01 primo volumio[4557]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 May 11 00:00:01 primo volumio[4557]: info: CoreCommandRouter::volumioGetState May 11 00:00:06 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 00:00:06 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 00:00:06 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam May 11 00:00:06 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam May 11 00:00:06 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject May 11 00:00:06 primo volumio[4557]: info: CoreCommandRouter::volumioGetBrowseSources May 11 00:00:06 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 11 00:00:07 primo volumio[4557]: error: MyVolumio Plugin failed to authenticate in a timely fashion May 11 00:00:07 primo volumio[4557]: info: Completed starting MyVolumio Plugin May 11 00:00:07 primo volumio[4557]: [Metrics] CommandRouter: 41s 356.17ms May 11 00:00:07 primo volumio[4557]: info: CoreCommandRouter::volumiosetStartupVolume May 11 00:00:07 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 11 00:00:07 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 11 00:00:07 primo volumio[4557]: info: CoreCommandRouter::Close All Modals sent May 11 00:00:07 primo volumio[4557]: info: CoreCommandRouter::Close All Modals sent May 11 00:00:07 primo volumio[4557]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav May 11 00:00:07 primo volumio[4557]: aplay: main:828: audio open error: Device or resource busy May 11 00:00:08 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable May 11 00:00:08 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 11 00:00:08 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect May 11 00:00:14 primo volumio[4557]: info: BOOT COMPLETED May 11 00:00:14 primo systemd[1]: Starting Daily man-db regeneration... May 11 00:00:14 primo systemd[1]: man-db.service: Succeeded. May 11 00:00:14 primo systemd[1]: Started Daily man-db regeneration. May 11 00:00:17 primo volumio[4557]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. May 11 00:00:17 primo volumio[4557]: info: Retrying Login Due to Network Error May 11 00:00:17 primo ntpd[1096]: 116.203.151.74 local addr 192.168.32.158 -> May 11 00:00:27 primo volumio[4557]: info: MyVolumio login type: Token May 11 00:00:48 primo volumio-remote-updater[584]: No test mode May 11 00:00:48 primo volumio-remote-updater[584]: No alpha test mode May 11 00:00:48 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled May 11 00:00:48 primo volumio[4557]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} May 11 00:00:48 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache May 11 00:00:57 primo volumio[4557]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. May 11 00:00:57 primo volumio[4557]: info: Retrying Login Due to Network Error May 11 00:01:07 primo volumio[4557]: info: MyVolumio login type: Token May 11 00:01:07 primo volumio[4557]: info: Clearing queue after UPNP request May 11 00:01:07 primo volumio[4557]: verbose: UNSET VOLATILE: Service: airplay_emulation May 11 00:01:07 primo volumio[4557]: info: Stopping Airplay Playback and sending pause command to client via USR2 May 11 00:01:07 primo sudo[5113]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 4793 May 11 00:01:07 primo sudo[5113]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 00:01:07 primo sudo[5113]: pam_unix(sudo:session): session closed for user root May 11 00:01:07 primo volumio[4557]: info: Shairport-Sync paused with USR2 May 11 00:01:07 primo volumio[4557]: info: CoreStateMachine::ClearQueue May 11 00:01:07 primo volumio[4557]: info: CoreStateMachine::stop May 11 00:01:07 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 00:01:07 primo volumio[4557]: info: CoreStateMachine::stPlaybackTimer May 11 00:01:07 primo volumio[4557]: info: CoreStateMachine::updateTrackBlock May 11 00:01:07 primo volumio[4557]: info: CorePlayQueue::getTrackBlock May 11 00:01:07 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:07 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:07 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:07 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:07 primo volumio[4557]: info: CoreStateMachine::serviceStop May 11 00:01:07 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:07 primo volumio[4557]: info: CoreCommandRouter::serviceStop May 11 00:01:07 primo volumio[4557]: info: ControllerMpd::stop May 11 00:01:07 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand stop May 11 00:01:07 primo volumio[4557]: info: CorePlayQueue::clearPlayQueue May 11 00:01:07 primo volumio[4557]: info: CorePlayQueue::saveQueue May 11 00:01:07 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:07 primo volumio[4557]: info: CoreCommandRouter::volumioPushQueue May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: sendMpdCommand stop took 22 milliseconds May 11 00:01:08 primo volumio[4557]: error: updateQueue error: null May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 6ms May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: error: updateQueue error: null May 11 00:01:08 primo volumio[4557]: error: updateQueue error: null May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 5ms May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 3ms May 11 00:01:08 primo volumio[4557]: info: Starting UPNP Playback May 11 00:01:08 primo volumio[4557]: info: Preparing playback through UPNP May 11 00:01:08 primo volumio[4557]: info: CoreCommandRouter::volumioGetState May 11 00:01:08 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:08 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService mpd May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 7ms May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 6ms May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 5ms May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 4ms May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 2ms May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 3ms May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 4ms May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 2ms May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 2ms May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 3ms May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 2ms May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 1ms May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 4ms May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 3ms May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 2ms May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: May 11 00:01:08 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:08 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 3ms May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 3ms May 11 00:01:08 primo volumio[4557]: info: ------------------------------ 2ms May 11 00:01:08 primo volumio[4557]: info: Restarting Shairport-Sync after stop May 11 00:01:08 primo sudo[5132]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 11 00:01:08 primo sudo[5132]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 00:01:08 primo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 11 00:01:08 primo shairport-sync[4793]: {"time":1746892787476,"response":"startAirplayPlayback Success"} May 11 00:01:08 primo systemd[1]: shairport-sync.service: Succeeded. May 11 00:01:08 primo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 11 00:01:08 primo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 11 00:01:08 primo sudo[5132]: pam_unix(sudo:session): session closed for user root May 11 00:01:08 primo volumio[4557]: info: Shairport-Sync retarted May 11 00:01:09 primo volumio[4557]: info: May 11 00:01:09 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:09 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:09 primo volumio[4557]: info: May 11 00:01:09 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:09 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:09 primo volumio[4557]: info: May 11 00:01:09 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:09 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:09 primo volumio[4557]: info: sendMpdCommand status took 204 milliseconds May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:09 primo volumio[4557]: info: May 11 00:01:09 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:09 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:09 primo volumio[4557]: info: sendMpdCommand status took 207 milliseconds May 11 00:01:09 primo volumio[4557]: info: sendMpdCommand status took 205 milliseconds May 11 00:01:09 primo volumio[4557]: info: sendMpdCommand playlistinfo took 3 milliseconds May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:09 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:09 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:09 primo volumio[4557]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":204,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"CAN'T DANCE","artist":"佐藤千亜妃","album":"TIME LEAP","uri":"http://m801.music.126.net/20250511002607/060f2c931a6d3d790268f4006ae75d2b/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/23977669628/be98/4907/b0c3/bde0909151ee553e70ef68cda9c88017.m4a?vuutv=xg1j1UfwSCQMu9363csR10qabuf9aNW8hqHuLYrZaCjpVh742N7wADdHh9BD224tIirdpmSdBTY+D80i4YOsJQg04a+HUKziidA8Z0d8UOc=","trackType":""} May 11 00:01:09 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::syncState stateService play May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus stop May 11 00:01:09 primo volumio[4557]: info: ------------------------------ 218ms May 11 00:01:09 primo volumio[4557]: info: May 11 00:01:09 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:09 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:09 primo volumio[4557]: info: May 11 00:01:09 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:09 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:09 primo volumio[4557]: info: sendMpdCommand status took 12 milliseconds May 11 00:01:09 primo volumio[4557]: info: sendMpdCommand playlistinfo took 11 milliseconds May 11 00:01:09 primo volumio[4557]: info: sendMpdCommand playlistinfo took 11 milliseconds May 11 00:01:09 primo volumio[4557]: info: sendMpdCommand status took 5 milliseconds May 11 00:01:09 primo volumio[4557]: info: sendMpdCommand status took 3 milliseconds May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:09 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:09 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:09 primo volumio[4557]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":204,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"CAN'T DANCE","artist":"佐藤千亜妃","album":"TIME LEAP","uri":"http://m801.music.126.net/20250511002607/060f2c931a6d3d790268f4006ae75d2b/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/23977669628/be98/4907/b0c3/bde0909151ee553e70ef68cda9c88017.m4a?vuutv=xg1j1UfwSCQMu9363csR10qabuf9aNW8hqHuLYrZaCjpVh742N7wADdHh9BD224tIirdpmSdBTY+D80i4YOsJQg04a+HUKziidA8Z0d8UOc=","trackType":""} May 11 00:01:09 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::syncState stateService play May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus play May 11 00:01:09 primo volumio[4557]: info: Received an update from plugin. extracting info from payload May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:09 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:09 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:09 primo volumio[4557]: verbose: STATE SERVICE {"status":"play","position":0,"seek":11,"duration":204,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"CAN'T DANCE","artist":"佐藤千亜妃","album":"TIME LEAP","uri":"http://m801.music.126.net/20250511002607/060f2c931a6d3d790268f4006ae75d2b/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/23977669628/be98/4907/b0c3/bde0909151ee553e70ef68cda9c88017.m4a?vuutv=xg1j1UfwSCQMu9363csR10qabuf9aNW8hqHuLYrZaCjpVh742N7wADdHh9BD224tIirdpmSdBTY+D80i4YOsJQg04a+HUKziidA8Z0d8UOc=","trackType":""} May 11 00:01:09 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::syncState stateService play May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus play May 11 00:01:09 primo volumio[4557]: info: Received an update from plugin. extracting info from payload May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:09 primo volumio[4557]: info: ------------------------------ 257ms May 11 00:01:09 primo volumio[4557]: info: ------------------------------ 257ms May 11 00:01:09 primo volumio[4557]: info: sendMpdCommand playlistinfo took 42 milliseconds May 11 00:01:09 primo volumio[4557]: info: sendMpdCommand playlistinfo took 41 milliseconds May 11 00:01:09 primo volumio[4557]: info: sendMpdCommand playlistinfo took 43 milliseconds May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:09 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:09 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:09 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:09 primo volumio[4557]: verbose: STATE SERVICE {"status":"play","position":0,"seek":857,"duration":204,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"CAN'T DANCE","artist":"佐藤千亜妃","album":"TIME LEAP","uri":"http://m801.music.126.net/20250511002607/060f2c931a6d3d790268f4006ae75d2b/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/23977669628/be98/4907/b0c3/bde0909151ee553e70ef68cda9c88017.m4a?vuutv=xg1j1UfwSCQMu9363csR10qabuf9aNW8hqHuLYrZaCjpVh742N7wADdHh9BD224tIirdpmSdBTY+D80i4YOsJQg04a+HUKziidA8Z0d8UOc=","trackType":""} May 11 00:01:09 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::syncState stateService play May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus play May 11 00:01:09 primo volumio[4557]: info: Received an update from plugin. extracting info from payload May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:09 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:09 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:09 primo volumio[4557]: verbose: STATE SERVICE {"status":"play","position":0,"seek":857,"duration":204,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"CAN'T DANCE","artist":"佐藤千亜妃","album":"TIME LEAP","uri":"http://m801.music.126.net/20250511002607/060f2c931a6d3d790268f4006ae75d2b/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/23977669628/be98/4907/b0c3/bde0909151ee553e70ef68cda9c88017.m4a?vuutv=xg1j1UfwSCQMu9363csR10qabuf9aNW8hqHuLYrZaCjpVh742N7wADdHh9BD224tIirdpmSdBTY+D80i4YOsJQg04a+HUKziidA8Z0d8UOc=","trackType":""} May 11 00:01:09 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::syncState stateService play May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus play May 11 00:01:09 primo volumio[4557]: info: Received an update from plugin. extracting info from payload May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:09 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:09 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:09 primo volumio[4557]: verbose: STATE SERVICE {"status":"play","position":0,"seek":857,"duration":204,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"CAN'T DANCE","artist":"佐藤千亜妃","album":"TIME LEAP","uri":"http://m801.music.126.net/20250511002607/060f2c931a6d3d790268f4006ae75d2b/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/23977669628/be98/4907/b0c3/bde0909151ee553e70ef68cda9c88017.m4a?vuutv=xg1j1UfwSCQMu9363csR10qabuf9aNW8hqHuLYrZaCjpVh742N7wADdHh9BD224tIirdpmSdBTY+D80i4YOsJQg04a+HUKziidA8Z0d8UOc=","trackType":""} May 11 00:01:09 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::syncState stateService play May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus play May 11 00:01:09 primo volumio[4557]: info: Received an update from plugin. extracting info from payload May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: albumart , getAlbumArt May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:09 primo volumio[4557]: info: ------------------------------ 130ms May 11 00:01:09 primo volumio[4557]: info: ------------------------------ 121ms May 11 00:01:09 primo volumio[4557]: info: ------------------------------ 121ms May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:09 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:09 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:09 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:09 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:09 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:09 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:09 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:09 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:09 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:09 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:09 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:09 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:09 primo volumio[4557]: An internal error occurred while serving an albumart. Details: Error: ENOENT: no such file or directory, stat '/data/albumart/web/%E4%BD%90%E8%97%A4%E5%8D%83%E4%BA%9C%E5%A6%83/TIME%20LEAP/bafe80f2-a7b9-4ac4-99e5-8993d51e21c7.jpg' May 11 00:01:09 primo volumio[1849]: 0 May 11 00:01:10 primo volumio[1849]: % Total % Received % Xferd Average Speed Time Time Time Current May 11 00:01:10 primo volumio[1849]: Dload Upload Total Spent Left Speed May 11 00:01:10 primo volumio[4557]: info: May 11 00:01:10 primo volumio[4557]: ---------------------------- Client requests Volume 1 May 11 00:01:10 primo volumio[4557]: info: VolumeController::SetAlsaVolume1 May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:10 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:10 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:10 primo volumio[1849]: [158B blob data] May 11 00:01:10 primo volumio[1849]: {"time":1746892870033,"response":"volume Success"}1 May 11 00:01:10 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:10 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:10 primo volumio[4557]: info: May 11 00:01:10 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:10 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:10 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:10 primo volumio[4557]: info: May 11 00:01:10 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:10 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:10 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:10 primo volumio[4557]: info: May 11 00:01:10 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:10 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:10 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:10 primo volumio[4557]: info: sendMpdCommand status took 2 milliseconds May 11 00:01:10 primo volumio[4557]: info: sendMpdCommand status took 2 milliseconds May 11 00:01:10 primo volumio[4557]: info: sendMpdCommand status took 1 milliseconds May 11 00:01:10 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:10 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:10 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:10 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:10 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:10 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:10 primo volumio[4557]: info: sendMpdCommand playlistinfo took 1 milliseconds May 11 00:01:10 primo volumio[4557]: info: sendMpdCommand playlistinfo took 2 milliseconds May 11 00:01:10 primo volumio[4557]: info: sendMpdCommand playlistinfo took 2 milliseconds May 11 00:01:10 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:10 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:10 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:10 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:10 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:10 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:10 primo volumio[4557]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2605,"duration":204,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"CAN'T DANCE","artist":"佐藤千亜妃","album":"TIME LEAP","uri":"http://m801.music.126.net/20250511002607/060f2c931a6d3d790268f4006ae75d2b/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/23977669628/be98/4907/b0c3/bde0909151ee553e70ef68cda9c88017.m4a?vuutv=xg1j1UfwSCQMu9363csR10qabuf9aNW8hqHuLYrZaCjpVh742N7wADdHh9BD224tIirdpmSdBTY+D80i4YOsJQg04a+HUKziidA8Z0d8UOc=","trackType":""} May 11 00:01:10 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::syncState stateService pause May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus play May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:10 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:10 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::stPlaybackTimer May 11 00:01:10 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:10 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:10 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:10 primo volumio[4557]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2605,"duration":204,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"CAN'T DANCE","artist":"佐藤千亜妃","album":"TIME LEAP","uri":"http://m801.music.126.net/20250511002607/060f2c931a6d3d790268f4006ae75d2b/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/23977669628/be98/4907/b0c3/bde0909151ee553e70ef68cda9c88017.m4a?vuutv=xg1j1UfwSCQMu9363csR10qabuf9aNW8hqHuLYrZaCjpVh742N7wADdHh9BD224tIirdpmSdBTY+D80i4YOsJQg04a+HUKziidA8Z0d8UOc=","trackType":""} May 11 00:01:10 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::syncState stateService pause May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus play May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:10 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::stPlaybackTimer May 11 00:01:10 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:10 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:10 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:10 primo volumio[4557]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2605,"duration":204,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"CAN'T DANCE","artist":"佐藤千亜妃","album":"TIME LEAP","uri":"http://m801.music.126.net/20250511002607/060f2c931a6d3d790268f4006ae75d2b/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/23977669628/be98/4907/b0c3/bde0909151ee553e70ef68cda9c88017.m4a?vuutv=xg1j1UfwSCQMu9363csR10qabuf9aNW8hqHuLYrZaCjpVh742N7wADdHh9BD224tIirdpmSdBTY+D80i4YOsJQg04a+HUKziidA8Z0d8UOc=","trackType":""} May 11 00:01:10 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::syncState stateService pause May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus play May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:10 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::stPlaybackTimer May 11 00:01:10 primo volumio[4557]: info: ------------------------------ 37ms May 11 00:01:10 primo volumio[4557]: info: ------------------------------ 36ms May 11 00:01:10 primo volumio[4557]: info: ------------------------------ 36ms May 11 00:01:10 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:10 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:10 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:10 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:10 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:10 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:10 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:13 primo volumio[4557]: info: May 11 00:01:13 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:13 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:13 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:13 primo volumio[4557]: info: May 11 00:01:13 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:13 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:13 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:13 primo volumio[4557]: info: May 11 00:01:13 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:13 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:13 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:13 primo volumio[4557]: info: sendMpdCommand status took 5 milliseconds May 11 00:01:13 primo volumio[4557]: info: sendMpdCommand status took 3 milliseconds May 11 00:01:13 primo volumio[4557]: info: sendMpdCommand status took 2 milliseconds May 11 00:01:13 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:13 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:13 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:13 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:13 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:13 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:13 primo volumio[4557]: info: sendMpdCommand playlistinfo took 2 milliseconds May 11 00:01:13 primo volumio[4557]: info: sendMpdCommand playlistinfo took 3 milliseconds May 11 00:01:13 primo volumio[4557]: info: sendMpdCommand playlistinfo took 2 milliseconds May 11 00:01:13 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:13 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:13 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:13 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:13 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:13 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:13 primo volumio[4557]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2000,"duration":204,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"CAN'T DANCE","artist":"佐藤千亜妃","album":"TIME LEAP","uri":"http://m801.music.126.net/20250511002607/060f2c931a6d3d790268f4006ae75d2b/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/23977669628/be98/4907/b0c3/bde0909151ee553e70ef68cda9c88017.m4a?vuutv=xg1j1UfwSCQMu9363csR10qabuf9aNW8hqHuLYrZaCjpVh742N7wADdHh9BD224tIirdpmSdBTY+D80i4YOsJQg04a+HUKziidA8Z0d8UOc=","trackType":""} May 11 00:01:13 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:13 primo volumio[4557]: info: CoreStateMachine::syncState stateService pause May 11 00:01:13 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus play May 11 00:01:13 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:13 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:13 primo volumio[4557]: info: CoreStateMachine::stPlaybackTimer May 11 00:01:13 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:13 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:13 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:13 primo volumio[4557]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2000,"duration":204,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"CAN'T DANCE","artist":"佐藤千亜妃","album":"TIME LEAP","uri":"http://m801.music.126.net/20250511002607/060f2c931a6d3d790268f4006ae75d2b/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/23977669628/be98/4907/b0c3/bde0909151ee553e70ef68cda9c88017.m4a?vuutv=xg1j1UfwSCQMu9363csR10qabuf9aNW8hqHuLYrZaCjpVh742N7wADdHh9BD224tIirdpmSdBTY+D80i4YOsJQg04a+HUKziidA8Z0d8UOc=","trackType":""} May 11 00:01:13 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:13 primo volumio[4557]: info: CoreStateMachine::syncState stateService pause May 11 00:01:13 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus play May 11 00:01:13 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:13 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:13 primo volumio[4557]: info: CoreStateMachine::stPlaybackTimer May 11 00:01:13 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:13 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:13 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:13 primo volumio[4557]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":2000,"duration":204,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"256 Kbps","isStreaming":false,"title":"CAN'T DANCE","artist":"佐藤千亜妃","album":"TIME LEAP","uri":"http://m801.music.126.net/20250511002607/060f2c931a6d3d790268f4006ae75d2b/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/23977669628/be98/4907/b0c3/bde0909151ee553e70ef68cda9c88017.m4a?vuutv=xg1j1UfwSCQMu9363csR10qabuf9aNW8hqHuLYrZaCjpVh742N7wADdHh9BD224tIirdpmSdBTY+D80i4YOsJQg04a+HUKziidA8Z0d8UOc=","trackType":""} May 11 00:01:13 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:13 primo volumio[4557]: info: CoreStateMachine::syncState stateService pause May 11 00:01:13 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus play May 11 00:01:13 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:13 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:13 primo volumio[4557]: info: CoreStateMachine::stPlaybackTimer May 11 00:01:13 primo volumio[4557]: info: ------------------------------ 41ms May 11 00:01:13 primo volumio[4557]: info: ------------------------------ 39ms May 11 00:01:13 primo volumio[4557]: info: ------------------------------ 39ms May 11 00:01:13 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:13 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:13 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:13 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:13 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:13 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:13 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:13 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:13 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:17 primo volumio[1849]: 35 May 11 00:01:18 primo volumio[1849]: % Total % Received % Xferd Average Speed Time Time Time Current May 11 00:01:18 primo volumio[1849]: Dload Upload Total Spent Left Speed May 11 00:01:18 primo volumio[4557]: info: May 11 00:01:18 primo volumio[4557]: ---------------------------- Client requests Volume 35 May 11 00:01:18 primo volumio[4557]: info: VolumeController::SetAlsaVolume35 May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:18 primo volumio[1849]: [158B blob data] May 11 00:01:18 primo volumio[1849]: {"time":1746892878017,"response":"volume Success"}35 May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:18 primo volumio[4557]: info: Airplay started streaming, receiving metadatas May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::volumioStop May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::stop May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::stPlaybackTimer May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::updateTrackBlock May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrackBlock May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::serviceStop May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: info: ControllerMpd::stop May 11 00:01:18 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand stop May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 00:01:18 primo volumio[4557]: info: Airplay started streaming, receiving metadatas May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::volumioStop May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::stop May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 00:01:18 primo volumio[4557]: info: Airplay started streaming, receiving metadatas May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::volumioStop May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::stop May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 00:01:18 primo shairport-sync[5138]: % Total % Received % Xferd Average Speed Time Time Time Current May 11 00:01:18 primo shairport-sync[5138]: Dload Upload Total Spent Left Speed May 11 00:01:18 primo volumio[4557]: info: May 11 00:01:18 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:18 primo volumio[4557]: info: sendMpdCommand stop took 15 milliseconds May 11 00:01:18 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:18 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:18 primo volumio[4557]: info: May 11 00:01:18 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:18 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:18 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:18 primo volumio[4557]: info: May 11 00:01:18 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:18 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:18 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:18 primo volumio[4557]: info: sendMpdCommand status took 7 milliseconds May 11 00:01:18 primo volumio[4557]: info: sendMpdCommand status took 5 milliseconds May 11 00:01:18 primo volumio[4557]: info: sendMpdCommand status took 3 milliseconds May 11 00:01:18 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:18 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:18 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:18 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:18 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:18 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:18 primo volumio[4557]: info: sendMpdCommand playlistinfo took 10 milliseconds May 11 00:01:18 primo volumio[4557]: info: sendMpdCommand playlistinfo took 10 milliseconds May 11 00:01:18 primo volumio[4557]: info: sendMpdCommand playlistinfo took 8 milliseconds May 11 00:01:18 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:18 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:18 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:18 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: 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":"CAN'T DANCE","artist":"佐藤千亜妃","album":"TIME LEAP","uri":"http://m801.music.126.net/20250511002607/060f2c931a6d3d790268f4006ae75d2b/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/23977669628/be98/4907/b0c3/bde0909151ee553e70ef68cda9c88017.m4a?vuutv=xg1j1UfwSCQMu9363csR10qabuf9aNW8hqHuLYrZaCjpVh742N7wADdHh9BD224tIirdpmSdBTY+D80i4YOsJQg04a+HUKziidA8Z0d8UOc=","trackType":""} May 11 00:01:18 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::syncState stateService stop May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus stop May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:18 primo volumio[4557]: info: No code May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:18 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: 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":"CAN'T DANCE","artist":"佐藤千亜妃","album":"TIME LEAP","uri":"http://m801.music.126.net/20250511002607/060f2c931a6d3d790268f4006ae75d2b/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/23977669628/be98/4907/b0c3/bde0909151ee553e70ef68cda9c88017.m4a?vuutv=xg1j1UfwSCQMu9363csR10qabuf9aNW8hqHuLYrZaCjpVh742N7wADdHh9BD224tIirdpmSdBTY+D80i4YOsJQg04a+HUKziidA8Z0d8UOc=","trackType":""} May 11 00:01:18 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::syncState stateService stop May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus stop May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:18 primo volumio[4557]: info: No code May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:18 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: 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":"CAN'T DANCE","artist":"佐藤千亜妃","album":"TIME LEAP","uri":"http://m801.music.126.net/20250511002607/060f2c931a6d3d790268f4006ae75d2b/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/23977669628/be98/4907/b0c3/bde0909151ee553e70ef68cda9c88017.m4a?vuutv=xg1j1UfwSCQMu9363csR10qabuf9aNW8hqHuLYrZaCjpVh742N7wADdHh9BD224tIirdpmSdBTY+D80i4YOsJQg04a+HUKziidA8Z0d8UOc=","trackType":""} May 11 00:01:18 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::syncState stateService stop May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus stop May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:18 primo volumio[4557]: info: No code May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:18 primo volumio[4557]: info: ------------------------------ 104ms May 11 00:01:18 primo volumio[4557]: info: ------------------------------ 101ms May 11 00:01:18 primo volumio[4557]: info: ------------------------------ 99ms May 11 00:01:18 primo volumio[4557]: info: May 11 00:01:18 primo volumio[4557]: ---------------------------- Client requests Start Airplay PlaybackRoutine May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback May 11 00:01:18 primo volumio[4557]: info: Airplay playback start May 11 00:01:18 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:18 primo volumio[4557]: info: CoreCommandRouter::volumioStop May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::stop May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 00:01:18 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 00:01:18 primo shairport-sync[5138]: [158B blob data] May 11 00:01:19 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:19 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:19 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:19 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:19 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:19 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:19 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:19 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:19 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:19 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:19 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:19 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:19 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:20 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:20 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:20 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:20 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:20 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:20 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:20 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:20 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:20 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:20 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:20 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:20 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:20 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:20 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:20 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:20 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:20 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:20 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:20 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:20 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:32 primo volumio[4557]: info: Clearing queue after UPNP request May 11 00:01:32 primo volumio[4557]: verbose: UNSET VOLATILE: Service: airplay_emulation May 11 00:01:32 primo volumio[4557]: info: Stopping Airplay Playback and sending pause command to client via USR2 May 11 00:01:32 primo sudo[5253]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/kill -USR2 5138 May 11 00:01:32 primo sudo[5253]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 00:01:32 primo sudo[5253]: pam_unix(sudo:session): session closed for user root May 11 00:01:32 primo volumio[4557]: info: Shairport-Sync paused with USR2 May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::ClearQueue May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::stop May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::stPlaybackTimer May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::updateTrackBlock May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrackBlock May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::serviceStop May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:32 primo volumio[4557]: info: ControllerMpd::stop May 11 00:01:32 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand stop May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::clearPlayQueue May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::saveQueue May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::volumioPushQueue May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:32 primo volumio[4557]: verbose: STATE SERVICE {"status":"pause","service":"airplay_emulation","title":"ギミギミ (给我给我)","artist":"BENI","album":"Best All Singles & Covers Hits","albumart":"/albumart?cacheid=452&web=BENI/Best%20All%20Singles%20%26%20Covers%20Hits/extralarge&path=&metadata=false","uri":"","trackType":"airplay","seek":20000,"duration":203,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"disableUiControls":true,"stream":false,"codec":"","repeatMode":"all"} May 11 00:01:32 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::syncState stateService pause May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus stop May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:32 primo volumio[4557]: verbose: STATE SERVICE {"status":"pause","service":"airplay_emulation","title":"ギミギミ (给我给我)","artist":"BENI","album":"Best All Singles & Covers Hits","albumart":"/albumart?cacheid=452&web=BENI/Best%20All%20Singles%20%26%20Covers%20Hits/extralarge&path=&metadata=false","uri":"","trackType":"airplay","seek":20000,"duration":203,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"disableUiControls":true,"stream":false,"codec":"","repeatMode":"all"} May 11 00:01:32 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::syncState stateService pause May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus stop May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:32 primo volumio[4557]: verbose: STATE SERVICE {"status":"pause","service":"airplay_emulation","title":"ギミギミ (给我给我)","artist":"BENI","album":"Best All Singles & Covers Hits","albumart":"/albumart?cacheid=452&web=BENI/Best%20All%20Singles%20%26%20Covers%20Hits/extralarge&path=&metadata=false","uri":"","trackType":"airplay","seek":20000,"duration":203,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"disableUiControls":true,"stream":false,"codec":"","repeatMode":"all"} May 11 00:01:32 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::syncState stateService pause May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus stop May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:32 primo volumio[4557]: verbose: STATE SERVICE {"status":"play","service":"airplay_emulation","title":"ギミギミ (给我给我)","artist":"BENI","album":"Best All Singles & Covers Hits","albumart":"/albumart?cacheid=452&web=BENI/Best%20All%20Singles%20%26%20Covers%20Hits/extralarge&path=&metadata=false","uri":"","trackType":"airplay","seek":20000,"duration":203,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"disableUiControls":true,"stream":false,"codec":"","repeatMode":"all"} May 11 00:01:32 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::syncState stateService play May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus stop May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:32 primo volumio[4557]: verbose: STATE SERVICE {"status":"play","service":"airplay_emulation","title":"ギミギミ (给我给我)","artist":"BENI","album":"Best All Singles & Covers Hits","albumart":"/albumart?cacheid=452&web=BENI/Best%20All%20Singles%20%26%20Covers%20Hits/extralarge&path=&metadata=false","uri":"","trackType":"airplay","seek":20000,"duration":203,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"disableUiControls":true,"stream":false,"codec":"","repeatMode":"all"} May 11 00:01:32 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::syncState stateService play May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus play May 11 00:01:32 primo volumio[4557]: info: Received an update from plugin. extracting info from payload May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:32 primo volumio[4557]: verbose: STATE SERVICE {"status":"play","service":"airplay_emulation","title":"ギミギミ (给我给我)","artist":"BENI","album":"Best All Singles & Covers Hits","albumart":"/albumart?cacheid=452&web=BENI/Best%20All%20Singles%20%26%20Covers%20Hits/extralarge&path=&metadata=false","uri":"","trackType":"airplay","seek":20000,"duration":203,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"disableUiControls":true,"stream":false,"codec":"","repeatMode":"all"} May 11 00:01:32 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::syncState stateService play May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus play May 11 00:01:32 primo volumio[4557]: info: Received an update from plugin. extracting info from payload May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: sendMpdCommand stop took 95 milliseconds May 11 00:01:32 primo volumio[4557]: error: updateQueue error: null May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 13ms May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: error: updateQueue error: null May 11 00:01:32 primo volumio[4557]: error: updateQueue error: null May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 8ms May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 6ms May 11 00:01:32 primo volumio[4557]: info: Starting UPNP Playback May 11 00:01:32 primo volumio[4557]: info: Preparing playback through UPNP May 11 00:01:32 primo volumio[4557]: info: CoreCommandRouter::volumioGetState May 11 00:01:32 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:32 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService mpd May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 3ms May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 3ms May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 2ms May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 3ms May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 3ms May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 2ms May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 2ms May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 1ms May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 2ms May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 3ms May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 2ms May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 2ms May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 4ms May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 4ms May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 3ms May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: May 11 00:01:32 primo volumio[4557]: ---------------------------- MPD announces system playlist update May 11 00:01:32 primo volumio[4557]: info: Ignoring MPD Status Update May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 3ms May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 1ms May 11 00:01:32 primo volumio[4557]: info: ------------------------------ 2ms May 11 00:01:33 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:33 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:33 primo volumio[4557]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received airplay_emulation May 11 00:01:33 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:33 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:33 primo volumio[4557]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received airplay_emulation May 11 00:01:33 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:33 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:33 primo volumio[4557]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received airplay_emulation May 11 00:01:33 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:33 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:33 primo volumio[4557]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received airplay_emulation May 11 00:01:33 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:33 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:33 primo volumio[4557]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received airplay_emulation May 11 00:01:33 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:33 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:33 primo volumio[4557]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received airplay_emulation May 11 00:01:33 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:33 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:33 primo volumio[4557]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received airplay_emulation May 11 00:01:33 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:33 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:33 primo volumio[4557]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received airplay_emulation May 11 00:01:33 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:33 primo volumio[4557]: verbose: In UPNP mode May 11 00:01:33 primo volumio[4557]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received airplay_emulation May 11 00:01:33 primo volumio[4557]: info: Restarting Shairport-Sync after stop May 11 00:01:33 primo sudo[5276]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 11 00:01:33 primo sudo[5276]: pam_unix(sudo:session): session opened for user root by (uid=0) May 11 00:01:33 primo systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 11 00:01:33 primo shairport-sync[5138]: {"time":1746892878230,"response":"startAirplayPlayback Success"} May 11 00:01:33 primo systemd[1]: shairport-sync.service: Succeeded. May 11 00:01:33 primo systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 11 00:01:33 primo systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 11 00:01:33 primo sudo[5276]: pam_unix(sudo:session): session closed for user root May 11 00:01:33 primo volumio[4557]: info: Shairport-Sync retarted May 11 00:01:33 primo volumio[1849]: 0 May 11 00:01:33 primo volumio[1849]: % Total % Received % Xferd Average Speed Time Time Time Current May 11 00:01:33 primo volumio[1849]: Dload Upload Total Spent Left Speed May 11 00:01:33 primo volumio[4557]: info: May 11 00:01:33 primo volumio[4557]: ---------------------------- Client requests Volume 1 May 11 00:01:33 primo volumio[4557]: info: VolumeController::SetAlsaVolume1 May 11 00:01:33 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:33 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:33 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:33 primo volumio[1849]: [158B blob data] May 11 00:01:33 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:33 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:33 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:33 primo volumio[1849]: {"time":1746892893923,"response":"volume Success"}1 May 11 00:01:36 primo volumio[4557]: info: May 11 00:01:36 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:36 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:36 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:36 primo volumio[4557]: info: May 11 00:01:36 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:36 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:36 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:36 primo volumio[4557]: info: May 11 00:01:36 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:36 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:36 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:36 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand clearerror May 11 00:01:36 primo volumio[4557]: info: sendMpdCommand status took 8 milliseconds May 11 00:01:36 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand clearerror May 11 00:01:36 primo volumio[4557]: info: sendMpdCommand status took 7 milliseconds May 11 00:01:36 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand clearerror May 11 00:01:36 primo volumio[4557]: info: sendMpdCommand status took 7 milliseconds May 11 00:01:36 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:36 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:36 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:36 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:36 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:36 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:36 primo volumio[4557]: info: sendMpdCommand clearerror took 12 milliseconds May 11 00:01:36 primo volumio[4557]: info: sendMpdCommand clearerror took 12 milliseconds May 11 00:01:36 primo volumio[4557]: info: sendMpdCommand clearerror took 11 milliseconds May 11 00:01:36 primo volumio[4557]: info: sendMpdCommand playlistinfo took 5 milliseconds May 11 00:01:36 primo volumio[4557]: info: sendMpdCommand playlistinfo took 4 milliseconds May 11 00:01:36 primo volumio[4557]: info: sendMpdCommand playlistinfo took 4 milliseconds May 11 00:01:36 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:36 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:36 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:36 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:36 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:36 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:36 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:36 primo volumio[4557]: 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":"Unknown (streaming?)","artist":"Unknown","album":"Unknown","uri":"http://m701.music.126.net/20250511002631/b63c3bad944efa119132bf3bb5834156/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/34566831901/aed7/f823/4d40/01e793f2ea9bcab876023254e3dfd197.m4a?vuutv=87UCs23QepXxFExnqSyq6T2BVy0IQYBf3f5hyPLY7B8S9YN+jzsMfGkT0TxZ9A7l3B2sM3ryadkXh7Ckk7dvUzPqmQpKi2WqXlALJj6vPpg=","trackType":""} May 11 00:01:36 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::syncState stateService stop May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus play May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::play index undefined May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:36 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:36 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:36 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:36 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:36 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:36 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:36 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:36 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:36 primo volumio[4557]: 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":"Unknown (streaming?)","artist":"Unknown","album":"Unknown","uri":"http://m701.music.126.net/20250511002631/b63c3bad944efa119132bf3bb5834156/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/34566831901/aed7/f823/4d40/01e793f2ea9bcab876023254e3dfd197.m4a?vuutv=87UCs23QepXxFExnqSyq6T2BVy0IQYBf3f5hyPLY7B8S9YN+jzsMfGkT0TxZ9A7l3B2sM3ryadkXh7Ckk7dvUzPqmQpKi2WqXlALJj6vPpg=","trackType":""} May 11 00:01:36 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::syncState stateService stop May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus stop May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:36 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:36 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:36 primo volumio[4557]: info: No code May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:36 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:36 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:36 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:36 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:36 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:36 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:36 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:36 primo volumio[4557]: 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":"Unknown (streaming?)","artist":"Unknown","album":"Unknown","uri":"http://m701.music.126.net/20250511002631/b63c3bad944efa119132bf3bb5834156/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/34566831901/aed7/f823/4d40/01e793f2ea9bcab876023254e3dfd197.m4a?vuutv=87UCs23QepXxFExnqSyq6T2BVy0IQYBf3f5hyPLY7B8S9YN+jzsMfGkT0TxZ9A7l3B2sM3ryadkXh7Ckk7dvUzPqmQpKi2WqXlALJj6vPpg=","trackType":""} May 11 00:01:36 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::syncState stateService stop May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus stop May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:36 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:36 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:36 primo volumio[4557]: info: No code May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:36 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:36 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:36 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:36 primo volumio[4557]: info: ------------------------------ 91ms May 11 00:01:36 primo volumio[4557]: info: ------------------------------ 90ms May 11 00:01:36 primo volumio[4557]: info: ------------------------------ 90ms May 11 00:01:36 primo volumio[4557]: info: CoreCommandRouter::volumioGetQueue May 11 00:01:36 primo volumio[4557]: info: CoreStateMachine::getQueue May 11 00:01:36 primo volumio[4557]: info: CorePlayQueue::getQueue May 11 00:01:37 primo volumio[4557]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. May 11 00:01:37 primo volumio[4557]: info: Retrying Login Due to Network Error May 11 00:01:44 primo volumio[4557]: info: Airplay started streaming, receiving metadatas May 11 00:01:44 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:44 primo volumio[4557]: info: CoreCommandRouter::volumioStop May 11 00:01:44 primo volumio[4557]: info: CoreStateMachine::stop May 11 00:01:44 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 00:01:44 primo volumio[4557]: info: Airplay started streaming, receiving metadatas May 11 00:01:44 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:44 primo volumio[4557]: info: CoreCommandRouter::volumioStop May 11 00:01:44 primo volumio[4557]: info: CoreStateMachine::stop May 11 00:01:44 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 00:01:44 primo volumio[4557]: info: Airplay started streaming, receiving metadatas May 11 00:01:44 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:44 primo volumio[4557]: info: CoreCommandRouter::volumioStop May 11 00:01:44 primo volumio[4557]: info: CoreStateMachine::stop May 11 00:01:44 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 00:01:44 primo shairport-sync[5282]: % Total % Received % Xferd Average Speed Time Time Time Current May 11 00:01:44 primo shairport-sync[5282]: Dload Upload Total Spent Left Speed May 11 00:01:44 primo volumio[4557]: info: May 11 00:01:44 primo volumio[4557]: ---------------------------- Client requests Start Airplay PlaybackRoutine May 11 00:01:44 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: airplay_emulation , startAirplayPlayback May 11 00:01:44 primo volumio[4557]: info: Airplay playback start May 11 00:01:44 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:44 primo volumio[4557]: info: CoreCommandRouter::volumioStop May 11 00:01:44 primo volumio[4557]: info: CoreStateMachine::stop May 11 00:01:44 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 00:01:44 primo shairport-sync[5282]: [158B blob data] May 11 00:01:45 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:45 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:45 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:45 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:45 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:45 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:45 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:45 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:45 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:45 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:45 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:45 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:45 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:46 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:46 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:46 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:46 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:46 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:46 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:46 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:46 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:46 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:46 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:46 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:46 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:46 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:46 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:46 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:46 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:46 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:46 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:46 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:46 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:47 primo volumio[4557]: info: MyVolumio login type: Token May 11 00:01:47 primo volumio[4557]: info: May 11 00:01:47 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:47 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:47 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:47 primo volumio[4557]: info: May 11 00:01:47 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:47 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:47 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:47 primo volumio[4557]: info: May 11 00:01:47 primo volumio[4557]: ---------------------------- MPD announces state update: player May 11 00:01:47 primo volumio[4557]: info: ControllerMpd::getState May 11 00:01:47 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand status May 11 00:01:47 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand clearerror May 11 00:01:47 primo volumio[4557]: info: sendMpdCommand status took 7 milliseconds May 11 00:01:47 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand clearerror May 11 00:01:47 primo volumio[4557]: info: sendMpdCommand status took 6 milliseconds May 11 00:01:47 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand clearerror May 11 00:01:47 primo volumio[4557]: info: sendMpdCommand status took 6 milliseconds May 11 00:01:47 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:47 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:47 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:47 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:47 primo volumio[4557]: verbose: ControllerMpd::parseState May 11 00:01:47 primo volumio[4557]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 11 00:01:47 primo volumio[4557]: info: sendMpdCommand clearerror took 16 milliseconds May 11 00:01:47 primo volumio[4557]: info: sendMpdCommand clearerror took 19 milliseconds May 11 00:01:47 primo volumio[4557]: info: sendMpdCommand playlistinfo took 11 milliseconds May 11 00:01:47 primo volumio[4557]: info: sendMpdCommand playlistinfo took 9 milliseconds May 11 00:01:47 primo volumio[4557]: info: sendMpdCommand playlistinfo took 8 milliseconds May 11 00:01:47 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:47 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:47 primo volumio[4557]: verbose: ControllerMpd::parseTrackInfo May 11 00:01:47 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:47 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:47 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:47 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:47 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:47 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:47 primo volumio[4557]: 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":"Unknown (streaming?)","artist":"Unknown","album":"Unknown","uri":"http://m701.music.126.net/20250511002631/b63c3bad944efa119132bf3bb5834156/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/34566831901/aed7/f823/4d40/01e793f2ea9bcab876023254e3dfd197.m4a?vuutv=87UCs23QepXxFExnqSyq6T2BVy0IQYBf3f5hyPLY7B8S9YN+jzsMfGkT0TxZ9A7l3B2sM3ryadkXh7Ckk7dvUzPqmQpKi2WqXlALJj6vPpg=","trackType":""} May 11 00:01:47 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:47 primo volumio[4557]: info: CoreStateMachine::syncState stateService stop May 11 00:01:47 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus play May 11 00:01:47 primo volumio[4557]: info: CoreStateMachine::play index undefined May 11 00:01:47 primo volumio[4557]: info: CoreStateMachine::setConsumeUpdateService undefined May 11 00:01:47 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:47 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:47 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:47 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:47 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:47 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:47 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:47 primo volumio[4557]: 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":"Unknown (streaming?)","artist":"Unknown","album":"Unknown","uri":"http://m701.music.126.net/20250511002631/b63c3bad944efa119132bf3bb5834156/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/34566831901/aed7/f823/4d40/01e793f2ea9bcab876023254e3dfd197.m4a?vuutv=87UCs23QepXxFExnqSyq6T2BVy0IQYBf3f5hyPLY7B8S9YN+jzsMfGkT0TxZ9A7l3B2sM3ryadkXh7Ckk7dvUzPqmQpKi2WqXlALJj6vPpg=","trackType":""} May 11 00:01:47 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:47 primo volumio[4557]: info: CoreStateMachine::syncState stateService stop May 11 00:01:47 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus stop May 11 00:01:47 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:47 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:47 primo volumio[4557]: info: No code May 11 00:01:47 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:47 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:47 primo volumio[4557]: info: ControllerMpd::pushState May 11 00:01:47 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:47 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:47 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:47 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:47 primo volumio[4557]: 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":"Unknown (streaming?)","artist":"Unknown","album":"Unknown","uri":"http://m701.music.126.net/20250511002631/b63c3bad944efa119132bf3bb5834156/jdyyaac/obj/w5rDlsOJwrLDjj7CmsOj/34566831901/aed7/f823/4d40/01e793f2ea9bcab876023254e3dfd197.m4a?vuutv=87UCs23QepXxFExnqSyq6T2BVy0IQYBf3f5hyPLY7B8S9YN+jzsMfGkT0TxZ9A7l3B2sM3ryadkXh7Ckk7dvUzPqmQpKi2WqXlALJj6vPpg=","trackType":""} May 11 00:01:47 primo volumio[4557]: verbose: CURRENT POSITION 0 May 11 00:01:47 primo volumio[4557]: info: CoreStateMachine::syncState stateService stop May 11 00:01:47 primo volumio[4557]: info: CoreStateMachine::syncState currentStatus stop May 11 00:01:47 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:47 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:47 primo volumio[4557]: info: No code May 11 00:01:47 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:47 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:47 primo volumio[4557]: info: CorePlayQueue::getTrack 0 May 11 00:01:47 primo volumio[4557]: info: ------------------------------ 100ms May 11 00:01:47 primo volumio[4557]: info: ------------------------------ 99ms May 11 00:01:47 primo volumio[4557]: info: ------------------------------ 99ms May 11 00:01:56 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:56 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:56 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:56 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:56 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:56 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:56 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:56 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:56 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:56 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:56 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:56 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:56 primo volumio[4557]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 11 00:01:56 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:56 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:56 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:56 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:56 primo volumio[4557]: info: CoreCommandRouter::servicePushState May 11 00:01:56 primo volumio[4557]: info: CoreStateMachine::pushState May 11 00:01:56 primo volumio[4557]: info: CoreCommandRouter::volumioPushState May 11 00:01:57 primo volumio[4557]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 11 00:01:57 primo volumio[4557]: Error: connect ETIMEDOUT 108.160.172.1:443 May 11 00:01:57 primo volumio[4557]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) { May 11 00:01:57 primo volumio[4557]: errno: -110, May 11 00:01:57 primo volumio[4557]: code: 'ETIMEDOUT', May 11 00:01:57 primo volumio[4557]: syscall: 'connect', May 11 00:01:57 primo volumio[4557]: address: '108.160.172.1', May 11 00:01:57 primo volumio[4557]: port: 443 May 11 00:01:57 primo volumio[4557]: } May 11 00:01:57 primo volumio[4557]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 11 00:01:57 primo sudo[5361]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-11 00:00 May 11 00:01:57 primo sudo[5361]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 09:53:51 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="53825f995260683aee752aed6b29f24e"