-- Logs begin at Thu 2025-05-29 14:47:59 JST, end at Thu 2025-05-29 17:45:09 JST. -- May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:00 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:00 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:00 volumio go-librespot[29295]: time="2025-05-29T17:44:00+09:00" level=debug msg="renewing login5 access token" May 29 17:44:00 volumio volumio[1006]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions May 29 17:44:00 volumio volumio[1006]: info: Preparing to save Alsa Options, stopping services first May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:00 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::volumioPause May 29 17:44:00 volumio volumio[1006]: info: CoreStateMachine::pause May 29 17:44:00 volumio volumio[1006]: info: CoreStateMachine::stPlaybackTimer May 29 17:44:00 volumio volumio[1006]: info: CoreStateMachine::servicePause May 29 17:44:00 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::servicePause May 29 17:44:00 volumio volumio[1006]: info: ControllerMpd::pause May 29 17:44:00 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand pause May 29 17:44:00 volumio volumio[1006]: info: Saving Audio Output to: {"output_device":{"value":"1","label":"Headphones"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 29 17:44:00 volumio go-librespot[29295]: time="2025-05-29T17:44:00+09:00" level=info msg="authenticated Login5 as makotomx" May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 29 17:44:00 volumio volumio[1006]: info: Found match in Cards Database: setting mixer PCM for card Headphones May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 29 17:44:00 volumio volumio[1006]: info: Updating Volume Controller Parameters: Device: 1 Name: Headphones Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 5 May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 29 17:44:00 volumio volumio[1006]: info: Disabling external Volume Control May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::getUIConfigOnPlugin May 29 17:44:00 volumio volumio[1006]: info: Preparing to generate the ALSA configuration file May 29 17:44:00 volumio volumio[1006]: info: May 29 17:44:00 volumio volumio[1006]: ---------------------------- MPD announces state update: player May 29 17:44:00 volumio volumio[1006]: info: sendMpdCommand pause took 331 milliseconds May 29 17:44:00 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:00 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:00 volumio volumio[1006]: info: sendMpdCommand status took 45 milliseconds May 29 17:44:00 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:00 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 29 17:44:00 volumio go-librespot[29295]: time="2025-05-29T17:44:00+09:00" level=debug msg="put connect state because VOLUME_CHANGED" May 29 17:44:00 volumio go-librespot[29295]: time="2025-05-29T17:44:00+09:00" level=trace msg="emitting websocket event: volume" May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 29 17:44:00 volumio volumio[1006]: info: Asound.conf file unchanged, so no further update is needed May 29 17:44:00 volumio volumio[1006]: info: Output device has changed, restarting MPD May 29 17:44:00 volumio sudo[19897]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 29 17:44:00 volumio sudo[19897]: pam_unix(sudo:session): session opened for user root by (uid=0) May 29 17:44:00 volumio volumio[1006]: info: Output device has changed, restarting Shairport Sync May 29 17:44:00 volumio sudo[19897]: pam_unix(sudo:session): session closed for user root May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 29 17:44:00 volumio sudo[19900]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 29 17:44:00 volumio sudo[19900]: pam_unix(sudo:session): session opened for user root by (uid=0) May 29 17:44:00 volumio systemd[1]: Stopping Music Player Daemon... May 29 17:44:00 volumio volumio[1006]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 29 17:44:00 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 376 milliseconds May 29 17:44:00 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:00 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:00 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:00 volumio volumio[1006]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":19725,"duration":257,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"255 Kbps","isStreaming":false,"title":"You May Be Right","artist":"Billy Joel","album":"Glass Houses","uri":"NAS/MyMusic/My Music/Billy Joel/1980. Billy Joel - Glass Houses (CBS 450087 2, Austria)/01 Billy Joel - You May Be Right.m4a","trackType":"m4a"} May 29 17:44:00 volumio volumio[1006]: verbose: CURRENT POSITION 0 May 29 17:44:00 volumio volumio[1006]: info: CoreStateMachine::syncState stateService pause May 29 17:44:00 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus pause May 29 17:44:00 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:00 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:00 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:00 volumio volumio[1006]: info: CoreStateMachine::stPlaybackTimer May 29 17:44:00 volumio volumio[1006]: info: ------------------------------ 436ms May 29 17:44:01 volumio volumio[1006]: SPOTIFY: received: {"type":"volume","data":{"value":20,"max":100}} May 29 17:44:01 volumio volumio[1006]: SPOTIFY: RECEIVED SPOTIFY VOLUME 20 May 29 17:44:01 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:01 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:01 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:01 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:01 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:01 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:01 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:01 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:01 volumio volumio[1006]: info: MPD Permissions set May 29 17:44:01 volumio volumio[1006]: info: VolumeController:: Volume=20 Mute =false May 29 17:44:01 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:01 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:01 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:01 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:01 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: pause | service: mpd | duration: 257 | title: You May Be Right | previous title: You May Be Right May 29 17:44:01 volumio volumio[1006]: info: =================> [timer] is active: false | can continue: true | timer started at: 1746891302097 May 29 17:44:01 volumio volumio[1006]: info: [LastFM] Song has been paused, so also pausing timer. May 29 17:44:01 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:01 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: pause | service: mpd | duration: 257 | title: You May Be Right | previous title: You May Be Right May 29 17:44:01 volumio volumio[1006]: info: =================> [timer] is active: false | can continue: true | timer started at: 1746891302097 May 29 17:44:01 volumio volumio[1006]: info: [LastFM] Song has been paused, so also pausing timer. May 29 17:44:01 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 May 29 17:44:01 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 May 29 17:44:01 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 29 17:44:01 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 29 17:44:01 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 29 17:44:01 volumio volumio[1006]: info: Starting Shairport Sync May 29 17:44:01 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:01 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:01 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:01 volumio sudo[19910]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 29 17:44:01 volumio sudo[19910]: pam_unix(sudo:session): session opened for user root by (uid=0) May 29 17:44:01 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 29 17:44:01 volumio systemd[1]: shairport-sync.service: Succeeded. May 29 17:44:01 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 29 17:44:01 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:01 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:01 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:01 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:01 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:01 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 29 17:44:01 volumio sudo[19910]: pam_unix(sudo:session): session closed for user root May 29 17:44:01 volumio volumio[1006]: info: Shairport-Sync Started May 29 17:44:01 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:01 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:02 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:02 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:02 volumio systemd[1]: mpd.service: Succeeded. May 29 17:44:02 volumio systemd[1]: Stopped Music Player Daemon. May 29 17:44:02 volumio systemd[1]: Starting Music Player Daemon... May 29 17:44:02 volumio sudo[19940]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 29 17:44:02 volumio sudo[19940]: pam_unix(sudo:session): session opened for user root by (uid=0) May 29 17:44:02 volumio sudo[19940]: pam_unix(sudo:session): session closed for user root May 29 17:44:02 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:02 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:02 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:02 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:02 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:02 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:02 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:02 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:04 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:04 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:04 volumio volumio[1006]: info: CoreCommandRouter::volumioRetrieveVolumeLevels May 29 17:44:04 volumio volumio[1006]: info: CoreStateMachine::getcurrentVolume May 29 17:44:04 volumio volumio[1006]: info: CoreCommandRouter::volumioRetrievevolume May 29 17:44:04 volumio volumio[1006]: info: VolumeController:: Volume=20 Mute =false May 29 17:44:04 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:04 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:04 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:04 volumio volumio[1006]: info: CoreStateMachine::updateTrackBlock May 29 17:44:04 volumio volumio[1006]: info: CorePlayQueue::getTrackBlock May 29 17:44:04 volumio volumio[1006]: info: CoreCommandRouter::volumioRetrievevolume May 29 17:44:04 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:04 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: pause | service: mpd | duration: 257 | title: You May Be Right | previous title: You May Be Right May 29 17:44:04 volumio volumio[1006]: info: =================> [timer] is active: false | can continue: true | timer started at: 1746891302097 May 29 17:44:04 volumio volumio[1006]: info: [LastFM] Song has been paused, so also pausing timer. May 29 17:44:04 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 May 29 17:44:04 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:04 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:04 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:04 volumio mpd[19943]: May 29 17:44 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 29 17:44:04 volumio volumio[1006]: info: VolumeController:: Volume=20 Mute =false May 29 17:44:04 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:04 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:04 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:04 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:04 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: pause | service: mpd | duration: 257 | title: You May Be Right | previous title: You May Be Right May 29 17:44:04 volumio volumio[1006]: info: =================> [timer] is active: false | can continue: true | timer started at: 1746891302097 May 29 17:44:04 volumio volumio[1006]: info: [LastFM] Song has been paused, so also pausing timer. May 29 17:44:04 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 May 29 17:44:04 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:04 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:04 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:04 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:04 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:04 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:04 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:04 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:04 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:04 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:04 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:05 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:05 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:05 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:05 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:06 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:06 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:06 volumio systemd[1]: Started Music Player Daemon. May 29 17:44:06 volumio sudo[19900]: pam_unix(sudo:session): session closed for user root May 29 17:44:06 volumio volumio[1006]: error: updateQueue error: null May 29 17:44:06 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:06 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:06 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:06 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:06 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:06 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:06 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:06 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:08 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:08 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:08 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:08 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:08 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:08 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:08 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:08 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:08 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:08 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:10 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:10 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:10 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:10 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:10 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:10 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:10 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:10 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:10 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:10 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:12 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:12 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:12 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:12 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:12 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:12 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:12 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:12 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:12 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:12 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:12 volumio volumio[1006]: info: CoreCommandRouter::volumioPlay May 29 17:44:12 volumio volumio[1006]: info: CoreStateMachine::play index undefined May 29 17:44:12 volumio volumio[1006]: info: CoreStateMachine::setConsumeUpdateService undefined May 29 17:44:12 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:12 volumio volumio[1006]: info: CoreStateMachine::startPlaybackTimer May 29 17:44:12 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:12 volumio volumio[1006]: info: ControllerMpd::resume May 29 17:44:12 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand play May 29 17:44:12 volumio volumio[1006]: info: sendMpdCommand play took 1 milliseconds May 29 17:44:14 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:14 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:14 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:14 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:14 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:14 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:14 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:14 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:14 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:14 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:15 volumio go-librespot[29295]: time="2025-05-29T17:44:15+09:00" level=trace msg="received accesspoint ping" May 29 17:44:15 volumio go-librespot[29295]: time="2025-05-29T17:44:15+09:00" level=trace msg="received accesspoint pong ack" May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::volumioNext May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::next May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::stop May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::setConsumeUpdateService undefined May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::updateTrackBlock May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrackBlock May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::stPlaybackTimer May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::serviceStop May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::serviceStop May 29 17:44:15 volumio volumio[1006]: info: ControllerMpd::stop May 29 17:44:15 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand stop May 29 17:44:15 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:15 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 257 | title: You May Be Right | previous title: You May Be Right May 29 17:44:15 volumio volumio[1006]: info: =================> [timer] is active: false | can continue: true | timer started at: 1746891302097 May 29 17:44:15 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 May 29 17:44:15 volumio volumio[1006]: info: sendMpdCommand stop took 10 milliseconds May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::play index undefined May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::setConsumeUpdateService undefined May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::startPlaybackTimer May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:15 volumio volumio[1006]: verbose: ControllerMpd::clearAddPlayTracks NAS/MyMusic/My Music/細野晴臣/HOSONO HOUSE/01 ろっか-ばい-まい-べいびい.mp3 May 29 17:44:15 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand stop May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::updateTrackBlock May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrackBlock May 29 17:44:15 volumio volumio[1006]: info: sendMpdCommand stop took 2 milliseconds May 29 17:44:15 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand clear May 29 17:44:15 volumio volumio[1006]: info: May 29 17:44:15 volumio volumio[1006]: ---------------------------- MPD announces system playlist update May 29 17:44:15 volumio volumio[1006]: info: Ignoring MPD Status Update May 29 17:44:15 volumio volumio[1006]: info: sendMpdCommand clear took 2 milliseconds May 29 17:44:15 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand add "NAS/MyMusic/My Music/細野晴臣/HOSONO HOUSE/01 ろっか-ばい-まい-べいびい.mp3" May 29 17:44:15 volumio volumio[1006]: error: updateQueue error: null May 29 17:44:15 volumio volumio[1006]: info: May 29 17:44:15 volumio volumio[1006]: ---------------------------- MPD announces system playlist update May 29 17:44:15 volumio volumio[1006]: info: Ignoring MPD Status Update May 29 17:44:15 volumio volumio[1006]: info: ------------------------------ 7ms May 29 17:44:15 volumio volumio[1006]: info: sendMpdCommand add "NAS/MyMusic/My Music/細野晴臣/HOSONO HOUSE/01 ろっか-ばい-まい-べいびい.mp3" took 5 milliseconds May 29 17:44:15 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand play May 29 17:44:15 volumio volumio[1006]: info: ------------------------------ 6ms May 29 17:44:15 volumio volumio[1006]: info: sendMpdCommand play took 4 milliseconds May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:15 volumio volumio[1006]: info: May 29 17:44:15 volumio volumio[1006]: ---------------------------- MPD announces state update: player May 29 17:44:15 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:15 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:15 volumio volumio[1006]: info: May 29 17:44:15 volumio volumio[1006]: ---------------------------- MPD announces state update: player May 29 17:44:15 volumio volumio[1006]: info: sendMpdCommand status took 10 milliseconds May 29 17:44:15 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:15 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:15 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:15 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:15 volumio volumio[1006]: info: sendMpdCommand status took 2 milliseconds May 29 17:44:15 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 2 milliseconds May 29 17:44:15 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:15 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:15 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:15 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:15 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":199,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"ろっか-ばい-まい-べいびい","artist":"細野晴臣","album":"HOSONO HOUSE","uri":"NAS/MyMusic/My Music/細野晴臣/HOSONO HOUSE/01 ろっか-ばい-まい-べいびい.mp3","trackType":"mp3"} May 29 17:44:15 volumio volumio[1006]: verbose: CURRENT POSITION 1 May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus stop May 29 17:44:15 volumio volumio[1006]: info: ------------------------------ 19ms May 29 17:44:15 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 3 milliseconds May 29 17:44:15 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:15 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:15 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":199,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"ろっか-ばい-まい-べいびい","artist":"細野晴臣","album":"HOSONO HOUSE","uri":"NAS/MyMusic/My Music/細野晴臣/HOSONO HOUSE/01 ろっか-ばい-まい-べいびい.mp3","trackType":"mp3"} May 29 17:44:15 volumio volumio[1006]: verbose: CURRENT POSITION 1 May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus play May 29 17:44:15 volumio volumio[1006]: info: Received an update from plugin. extracting info from payload May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:15 volumio volumio[1006]: info: ------------------------------ 37ms May 29 17:44:15 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:15 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 199 | title: ろっか-ばい-まい-べいびい | previous title: You May Be Right May 29 17:44:15 volumio volumio[1006]: info: =================> [timer] is active: false | can continue: true | timer started at: 1746891302097 May 29 17:44:15 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:15 volumio volumio[1006]: info: [LastFM] Current track has sufficient metadata: title (ろっか-ばい-まい-べいびい) and artist (細野晴臣) passed on explicitly May 29 17:44:15 volumio volumio[1006]: info: [LastFM] Updating now playing May 29 17:44:15 volumio volumio[1006]: info: [LastFM] starting new timer for 109450 milliseconds [細野晴臣 - ろっか-ばい-まい-べいびい]. May 29 17:44:15 volumio volumio[1006]: -------------------------------------------------// S T O P P I N G May 29 17:44:15 volumio volumio[1006]: -------------------------------------------------// S T A R T I N G May 29 17:44:15 volumio volumio[1006]: info: [LastFM] Timer started with time stamp 1748508255 May 29 17:44:15 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:15 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 199 | title: ろっか-ばい-まい-べいびい | previous title: ろっか-ばい-まい-べいびい May 29 17:44:15 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508255542 May 29 17:44:15 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:15 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:15 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 May 29 17:44:15 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:15 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:15 volumio volumio[1006]: info: [LastFM] updated "now playing" | artist: 細野晴臣 | title: ろっか-ばい-まい-べいびい May 29 17:44:15 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:15 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:16 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:16 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:16 volumio volumio[1006]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"ろっか-ばい-まい-べいびい","url":"https://www.last.fm/music/%E7%B4%B0%E9%87%8E%E6%99%B4%E8%87%A3/_/%E3%82%8D%E3%81%A3%E3%81%8B-%E3%81%B0%E3%81%84-%E3%81%BE%E3%81%84-%E3%81%B9%E3%81%84%E3%81%B3%E3%81%84","duration":"0","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"1","playcount":"1","artist":{"name":"細野晴臣","mbid":"078be324-de92-4c72-9371-65bdcf324154","url":"https://www.last.fm/music/%E7%B4%B0%E9%87%8E%E6%99%B4%E8%87%A3"},"userplaycount":"1","userloved":"0","toptags":""}} May 29 17:44:16 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:16 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:16 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:16 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:16 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:16 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:16 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:16 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioNext May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::next May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::stop May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::setConsumeUpdateService undefined May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::stPlaybackTimer May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::updateTrackBlock May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrackBlock May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::serviceStop May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 1 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::serviceStop May 29 17:44:18 volumio volumio[1006]: info: ControllerMpd::stop May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand stop May 29 17:44:18 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:18 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 199 | title: ろっか-ばい-まい-べいびい | previous title: ろっか-ばい-まい-べいびい May 29 17:44:18 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508255542 May 29 17:44:18 volumio volumio[1006]: info: [LastFM] stopping timer, playback has ended. May 29 17:44:18 volumio volumio[1006]: -------------------------------------------------// S T O P P I N G May 29 17:44:18 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 May 29 17:44:18 volumio volumio[1006]: info: May 29 17:44:18 volumio volumio[1006]: ---------------------------- MPD announces state update: player May 29 17:44:18 volumio volumio[1006]: info: sendMpdCommand stop took 11 milliseconds May 29 17:44:18 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::play index undefined May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::setConsumeUpdateService undefined May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::startPlaybackTimer May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::clearAddPlayTracks NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand stop May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::updateTrackBlock May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrackBlock May 29 17:44:18 volumio volumio[1006]: info: sendMpdCommand status took 4 milliseconds May 29 17:44:18 volumio volumio[1006]: info: sendMpdCommand stop took 2 milliseconds May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand clear May 29 17:44:18 volumio volumio[1006]: info: May 29 17:44:18 volumio volumio[1006]: ---------------------------- MPD announces system playlist update May 29 17:44:18 volumio volumio[1006]: info: Ignoring MPD Status Update May 29 17:44:18 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 3 milliseconds May 29 17:44:18 volumio volumio[1006]: info: sendMpdCommand clear took 3 milliseconds May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand add "NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a" May 29 17:44:18 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: 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":"ろっか-ばい-まい-べいびい","artist":"細野晴臣","album":"HOSONO HOUSE","uri":"NAS/MyMusic/My Music/細野晴臣/HOSONO HOUSE/01 ろっか-ばい-まい-べいびい.mp3","trackType":"mp3"} May 29 17:44:18 volumio volumio[1006]: verbose: CURRENT POSITION 2 May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::syncState stateService stop May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus stop May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:18 volumio volumio[1006]: info: No code May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:18 volumio volumio[1006]: info: ------------------------------ 29ms May 29 17:44:18 volumio volumio[1006]: error: updateQueue error: null May 29 17:44:18 volumio volumio[1006]: info: May 29 17:44:18 volumio volumio[1006]: ---------------------------- MPD announces system playlist update May 29 17:44:18 volumio volumio[1006]: info: Ignoring MPD Status Update May 29 17:44:18 volumio volumio[1006]: info: ------------------------------ 28ms May 29 17:44:18 volumio volumio[1006]: info: sendMpdCommand add "NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a" took 25 milliseconds May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand play May 29 17:44:18 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:18 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 169 | title: 恋は桃色 | previous title: ろっか-ばい-まい-べいびい May 29 17:44:18 volumio volumio[1006]: info: =================> [timer] is active: false | can continue: false | timer started at: 1748508255542 May 29 17:44:18 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:18 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 169 | title: 恋は桃色 | previous title: ろっか-ばい-まい-べいびい May 29 17:44:18 volumio volumio[1006]: info: =================> [timer] is active: false | can continue: false | timer started at: 1748508255542 May 29 17:44:18 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:18 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 169 | title: 恋は桃色 | previous title: ろっか-ばい-まい-べいびい May 29 17:44:18 volumio volumio[1006]: info: =================> [timer] is active: false | can continue: false | timer started at: 1748508255542 May 29 17:44:18 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 May 29 17:44:18 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 May 29 17:44:18 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 May 29 17:44:18 volumio volumio[1006]: info: ------------------------------ 20ms May 29 17:44:18 volumio volumio[1006]: info: sendMpdCommand play took 18 milliseconds May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: May 29 17:44:18 volumio volumio[1006]: ---------------------------- MPD announces state update: player May 29 17:44:18 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:18 volumio volumio[1006]: info: May 29 17:44:18 volumio volumio[1006]: ---------------------------- MPD announces state update: player May 29 17:44:18 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:18 volumio volumio[1006]: info: sendMpdCommand status took 6 milliseconds May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:18 volumio volumio[1006]: info: sendMpdCommand status took 5 milliseconds May 29 17:44:18 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 3 milliseconds May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:18 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":169,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"252 Kbps","isStreaming":false,"title":"恋は桃色","artist":"Pearl & The Oysters","album":"HOSONO HOUSE COVERS","uri":"NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a","trackType":"m4a"} May 29 17:44:18 volumio volumio[1006]: verbose: CURRENT POSITION 2 May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus stop May 29 17:44:18 volumio volumio[1006]: info: ------------------------------ 17ms May 29 17:44:18 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 6 milliseconds May 29 17:44:18 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:18 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":731,"duration":169,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"252 Kbps","isStreaming":false,"title":"恋は桃色","artist":"Pearl & The Oysters","album":"HOSONO HOUSE COVERS","uri":"NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a","trackType":"m4a"} May 29 17:44:18 volumio volumio[1006]: verbose: CURRENT POSITION 2 May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus play May 29 17:44:18 volumio volumio[1006]: info: Received an update from plugin. extracting info from payload May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:18 volumio volumio[1006]: info: ------------------------------ 48ms May 29 17:44:18 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:18 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: ろっか-ばい-まい-べいびい May 29 17:44:18 volumio volumio[1006]: info: =================> [timer] is active: false | can continue: false | timer started at: 1748508255542 May 29 17:44:18 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:18 volumio volumio[1006]: info: [LastFM] Current track has sufficient metadata: title (恋は桃色) and artist (Pearl & The Oysters) passed on explicitly May 29 17:44:18 volumio volumio[1006]: info: [LastFM] Updating now playing May 29 17:44:18 volumio volumio[1006]: info: [LastFM] starting new timer for 92950 milliseconds [Pearl & The Oysters - 恋は桃色]. May 29 17:44:18 volumio volumio[1006]: -------------------------------------------------// S T A R T I N G May 29 17:44:18 volumio volumio[1006]: info: [LastFM] Timer started with time stamp 1748508258 May 29 17:44:18 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:18 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:18 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:18 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:18 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:18 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 May 29 17:44:18 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:18 volumio volumio[1006]: info: [LastFM] track info: {"success":true,"trackInfo":{"name":"恋は桃色","url":"https://www.last.fm/music/PEARL+&+THE+OYSTERS/_/%E6%81%8B%E3%81%AF%E6%A1%83%E8%89%B2","duration":"0","streamable":{"#":"0","@":{"fulltrack":"0"}},"listeners":"436","playcount":"1274","artist":{"name":"PEARL & THE OYSTERS","url":"https://www.last.fm/music/PEARL+&+THE+OYSTERS"},"userplaycount":"0","userloved":"0","toptags":""}} May 29 17:44:18 volumio volumio[1006]: info: [LastFM] updated "now playing" | artist: Pearl & The Oysters | title: 恋は桃色 May 29 17:44:18 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:18 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:18 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:19 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:19 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:19 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:19 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:19 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:19 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:19 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:19 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:19 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:20 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:20 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:20 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:20 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:20 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:20 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:20 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:20 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:20 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:20 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:21 volumio volumio[1006]: info: VolumeController::SetAlsaVolume25 May 29 17:44:21 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:21 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:21 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:21 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:22 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:22 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:22 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:22 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 May 29 17:44:22 volumio volumio[1006]: SPOTIFY: SPOTIFY VOLUME 20 May 29 17:44:22 volumio volumio[1006]: SPOTIFY: VOLUMIO VOLUME 25 May 29 17:44:22 volumio volumio[1006]: SPOTIFY: DELTA VOLUME ENOUGH: true May 29 17:44:22 volumio volumio[1006]: info: Setting Spotify Volume from Volumio: 25 May 29 17:44:22 volumio volumio[1006]: info: May 29 17:44:22 volumio volumio[1006]: ---------------------------- MPD announces state update: mixer May 29 17:44:22 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:22 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:22 volumio volumio[1006]: info: sendMpdCommand status took 9 milliseconds May 29 17:44:22 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:22 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:22 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 5 milliseconds May 29 17:44:22 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:22 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":4479,"duration":169,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"252 Kbps","isStreaming":false,"title":"恋は桃色","artist":"Pearl & The Oysters","album":"HOSONO HOUSE COVERS","uri":"NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a","trackType":"m4a"} May 29 17:44:22 volumio volumio[1006]: verbose: CURRENT POSITION 2 May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus play May 29 17:44:22 volumio volumio[1006]: info: Received an update from plugin. extracting info from payload May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:22 volumio volumio[1006]: info: ------------------------------ 33ms May 29 17:44:22 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:22 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:22 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:22 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:22 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:22 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:22 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 May 29 17:44:22 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: VolumeController::SetAlsaVolume30 May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:22 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:22 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:22 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:22 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 May 29 17:44:22 volumio volumio[1006]: SPOTIFY: SPOTIFY VOLUME 25 May 29 17:44:22 volumio volumio[1006]: SPOTIFY: VOLUMIO VOLUME 30 May 29 17:44:22 volumio volumio[1006]: SPOTIFY: DELTA VOLUME ENOUGH: true May 29 17:44:22 volumio volumio[1006]: info: Setting Spotify Volume from Volumio: 30 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: May 29 17:44:22 volumio volumio[1006]: ---------------------------- MPD announces state update: mixer May 29 17:44:22 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:22 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:22 volumio volumio[1006]: info: sendMpdCommand status took 2 milliseconds May 29 17:44:22 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:22 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:22 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 1 milliseconds May 29 17:44:22 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:22 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":4605,"duration":169,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"252 Kbps","isStreaming":false,"title":"恋は桃色","artist":"Pearl & The Oysters","album":"HOSONO HOUSE COVERS","uri":"NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a","trackType":"m4a"} May 29 17:44:22 volumio volumio[1006]: verbose: CURRENT POSITION 2 May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus play May 29 17:44:22 volumio volumio[1006]: info: Received an update from plugin. extracting info from payload May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:22 volumio volumio[1006]: info: ------------------------------ 26ms May 29 17:44:22 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:22 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:22 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:22 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:22 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:22 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:22 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 May 29 17:44:22 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: VolumeController::SetAlsaVolume35 May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:22 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:22 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:22 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:22 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 May 29 17:44:22 volumio volumio[1006]: SPOTIFY: SPOTIFY VOLUME 30 May 29 17:44:22 volumio volumio[1006]: SPOTIFY: VOLUMIO VOLUME 35 May 29 17:44:22 volumio volumio[1006]: SPOTIFY: DELTA VOLUME ENOUGH: true May 29 17:44:22 volumio volumio[1006]: info: Setting Spotify Volume from Volumio: 35 May 29 17:44:22 volumio volumio[1006]: info: May 29 17:44:22 volumio volumio[1006]: ---------------------------- MPD announces state update: mixer May 29 17:44:22 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:22 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:22 volumio volumio[1006]: info: sendMpdCommand status took 3 milliseconds May 29 17:44:22 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:22 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:22 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 2 milliseconds May 29 17:44:22 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:22 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5234,"duration":169,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"252 Kbps","isStreaming":false,"title":"恋は桃色","artist":"Pearl & The Oysters","album":"HOSONO HOUSE COVERS","uri":"NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a","trackType":"m4a"} May 29 17:44:22 volumio volumio[1006]: verbose: CURRENT POSITION 2 May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus play May 29 17:44:22 volumio volumio[1006]: info: Received an update from plugin. extracting info from payload May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:22 volumio volumio[1006]: info: ------------------------------ 33ms May 29 17:44:22 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:22 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:22 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:22 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:22 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:22 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:22 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:22 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 May 29 17:44:22 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:22 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:22 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:22 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: VolumeController::SetAlsaVolume40 May 29 17:44:23 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:23 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:23 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:23 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:23 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:23 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 May 29 17:44:23 volumio volumio[1006]: SPOTIFY: SPOTIFY VOLUME 35 May 29 17:44:23 volumio volumio[1006]: SPOTIFY: VOLUMIO VOLUME 40 May 29 17:44:23 volumio volumio[1006]: SPOTIFY: DELTA VOLUME ENOUGH: true May 29 17:44:23 volumio volumio[1006]: info: Setting Spotify Volume from Volumio: 40 May 29 17:44:23 volumio volumio[1006]: info: May 29 17:44:23 volumio volumio[1006]: ---------------------------- MPD announces state update: mixer May 29 17:44:23 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:23 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:23 volumio volumio[1006]: info: sendMpdCommand status took 2 milliseconds May 29 17:44:23 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:23 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:23 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 2 milliseconds May 29 17:44:23 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:23 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5485,"duration":169,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"252 Kbps","isStreaming":false,"title":"恋は桃色","artist":"Pearl & The Oysters","album":"HOSONO HOUSE COVERS","uri":"NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a","trackType":"m4a"} May 29 17:44:23 volumio volumio[1006]: verbose: CURRENT POSITION 2 May 29 17:44:23 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:44:23 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus play May 29 17:44:23 volumio volumio[1006]: info: Received an update from plugin. extracting info from payload May 29 17:44:23 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:23 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:23 volumio volumio[1006]: info: ------------------------------ 25ms May 29 17:44:23 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:23 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:23 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:23 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:23 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:23 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:23 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:23 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:23 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:23 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:23 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 May 29 17:44:23 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 40 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:23 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: VolumeController::SetAlsaVolume45 May 29 17:44:23 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:23 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:23 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:23 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:23 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:23 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 May 29 17:44:23 volumio volumio[1006]: SPOTIFY: SPOTIFY VOLUME 40 May 29 17:44:23 volumio volumio[1006]: SPOTIFY: VOLUMIO VOLUME 45 May 29 17:44:23 volumio volumio[1006]: SPOTIFY: DELTA VOLUME ENOUGH: true May 29 17:44:23 volumio volumio[1006]: info: Setting Spotify Volume from Volumio: 45 May 29 17:44:23 volumio volumio[1006]: info: May 29 17:44:23 volumio volumio[1006]: ---------------------------- MPD announces state update: mixer May 29 17:44:23 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:23 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:23 volumio volumio[1006]: info: sendMpdCommand status took 3 milliseconds May 29 17:44:23 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:23 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:23 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 1 milliseconds May 29 17:44:23 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:23 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":5862,"duration":169,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"252 Kbps","isStreaming":false,"title":"恋は桃色","artist":"Pearl & The Oysters","album":"HOSONO HOUSE COVERS","uri":"NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a","trackType":"m4a"} May 29 17:44:23 volumio volumio[1006]: verbose: CURRENT POSITION 2 May 29 17:44:23 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:44:23 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus play May 29 17:44:23 volumio volumio[1006]: info: Received an update from plugin. extracting info from payload May 29 17:44:23 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:23 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:23 volumio volumio[1006]: info: ------------------------------ 24ms May 29 17:44:23 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:23 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:23 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:23 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:23 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:23 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:23 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:23 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:23 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:23 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:23 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 May 29 17:44:23 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:23 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:23 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:23 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:24 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:24 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:24 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:24 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:24 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:24 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:24 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:24 volumio volumio[1006]: SPOTIFY: SETTING SPOTIFY VOLUME 45 May 29 17:44:24 volumio volumio[1006]: info: Sending Spotify command with payload to local API: /player/volume May 29 17:44:24 volumio go-librespot[29295]: time="2025-05-29T17:44:24+09:00" level=debug msg="update volume to 29490/65535" May 29 17:44:24 volumio volumio[1006]: info: VolumeController::SetAlsaVolume50 May 29 17:44:24 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:24 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:24 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:24 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:24 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:24 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:24 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 29 17:44:24 volumio volumio[1006]: SPOTIFY: SPOTIFY VOLUME 45 May 29 17:44:24 volumio volumio[1006]: SPOTIFY: VOLUMIO VOLUME 50 May 29 17:44:24 volumio volumio[1006]: SPOTIFY: DELTA VOLUME ENOUGH: true May 29 17:44:24 volumio volumio[1006]: info: Setting Spotify Volume from Volumio: 50 May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:24 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:24 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: May 29 17:44:25 volumio volumio[1006]: ---------------------------- MPD announces state update: mixer May 29 17:44:25 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:25 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:25 volumio volumio[1006]: info: sendMpdCommand status took 1 milliseconds May 29 17:44:25 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:25 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:25 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 2 milliseconds May 29 17:44:25 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:25 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7360,"duration":169,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"252 Kbps","isStreaming":false,"title":"恋は桃色","artist":"Pearl & The Oysters","album":"HOSONO HOUSE COVERS","uri":"NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a","trackType":"m4a"} May 29 17:44:25 volumio volumio[1006]: verbose: CURRENT POSITION 2 May 29 17:44:25 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:44:25 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus play May 29 17:44:25 volumio volumio[1006]: info: Received an update from plugin. extracting info from payload May 29 17:44:25 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:25 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:25 volumio volumio[1006]: info: ------------------------------ 23ms May 29 17:44:25 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:25 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:25 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:25 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:25 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:25 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:25 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:25 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:25 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:25 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:25 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 29 17:44:25 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: VolumeController::SetAlsaVolume60 May 29 17:44:25 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:25 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:25 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:25 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:25 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:25 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:25 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 May 29 17:44:25 volumio volumio[1006]: SPOTIFY: SPOTIFY VOLUME 50 May 29 17:44:25 volumio volumio[1006]: SPOTIFY: VOLUMIO VOLUME 60 May 29 17:44:25 volumio volumio[1006]: SPOTIFY: DELTA VOLUME ENOUGH: true May 29 17:44:25 volumio volumio[1006]: info: Setting Spotify Volume from Volumio: 60 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:25 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: May 29 17:44:25 volumio volumio[1006]: ---------------------------- MPD announces state update: mixer May 29 17:44:25 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:25 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:25 volumio volumio[1006]: info: sendMpdCommand status took 3 milliseconds May 29 17:44:25 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:25 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:25 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 1 milliseconds May 29 17:44:25 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:25 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":7611,"duration":169,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"252 Kbps","isStreaming":false,"title":"恋は桃色","artist":"Pearl & The Oysters","album":"HOSONO HOUSE COVERS","uri":"NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a","trackType":"m4a"} May 29 17:44:25 volumio volumio[1006]: verbose: CURRENT POSITION 2 May 29 17:44:25 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:44:25 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus play May 29 17:44:25 volumio volumio[1006]: info: Received an update from plugin. extracting info from payload May 29 17:44:25 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:25 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:25 volumio volumio[1006]: info: ------------------------------ 27ms May 29 17:44:25 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:25 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:25 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:25 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:25 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:25 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:25 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:25 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:25 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:25 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:25 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 May 29 17:44:25 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:25 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:25 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:25 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:25 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:25 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:25 volumio go-librespot[29295]: time="2025-05-29T17:44:25+09:00" level=debug msg="put connect state because VOLUME_CHANGED" May 29 17:44:25 volumio go-librespot[29295]: time="2025-05-29T17:44:25+09:00" level=trace msg="emitting websocket event: volume" May 29 17:44:25 volumio volumio[1006]: SPOTIFY: received: {"type":"volume","data":{"value":45,"max":100}} May 29 17:44:25 volumio volumio[1006]: SPOTIFY: RECEIVED SPOTIFY VOLUME 45 May 29 17:44:25 volumio volumio[1006]: info: Setting Volumio Volume from Spotify: 45 May 29 17:44:25 volumio volumio[1006]: info: VolumeController::SetAlsaVolume45 May 29 17:44:26 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:26 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:26 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:26 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:26 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:26 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:26 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: May 29 17:44:26 volumio volumio[1006]: ---------------------------- MPD announces state update: mixer May 29 17:44:26 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:26 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:26 volumio volumio[1006]: info: sendMpdCommand status took 2 milliseconds May 29 17:44:26 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:26 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:26 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 3 milliseconds May 29 17:44:26 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:26 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":8480,"duration":169,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"252 Kbps","isStreaming":false,"title":"恋は桃色","artist":"Pearl & The Oysters","album":"HOSONO HOUSE COVERS","uri":"NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a","trackType":"m4a"} May 29 17:44:26 volumio volumio[1006]: verbose: CURRENT POSITION 2 May 29 17:44:26 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:44:26 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus play May 29 17:44:26 volumio volumio[1006]: info: Received an update from plugin. extracting info from payload May 29 17:44:26 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:26 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:26 volumio volumio[1006]: info: ------------------------------ 32ms May 29 17:44:26 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:26 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:26 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:26 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:26 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:26 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:26 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:26 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:26 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:26 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:26 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 May 29 17:44:26 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:26 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: VolumeController::SetAlsaVolume60 May 29 17:44:26 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:26 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:26 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:26 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:26 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:26 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:26 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 May 29 17:44:26 volumio volumio[1006]: SPOTIFY: SPOTIFY VOLUME 45 May 29 17:44:26 volumio volumio[1006]: SPOTIFY: VOLUMIO VOLUME 60 May 29 17:44:26 volumio volumio[1006]: SPOTIFY: DELTA VOLUME ENOUGH: true May 29 17:44:26 volumio volumio[1006]: info: Setting Spotify Volume from Volumio: 60 May 29 17:44:26 volumio volumio[1006]: info: May 29 17:44:26 volumio volumio[1006]: ---------------------------- MPD announces state update: mixer May 29 17:44:26 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:26 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:26 volumio volumio[1006]: info: sendMpdCommand status took 2 milliseconds May 29 17:44:26 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:26 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:26 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 2 milliseconds May 29 17:44:26 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:26 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":9108,"duration":169,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"252 Kbps","isStreaming":false,"title":"恋は桃色","artist":"Pearl & The Oysters","album":"HOSONO HOUSE COVERS","uri":"NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a","trackType":"m4a"} May 29 17:44:26 volumio volumio[1006]: verbose: CURRENT POSITION 2 May 29 17:44:26 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:44:26 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus play May 29 17:44:26 volumio volumio[1006]: info: Received an update from plugin. extracting info from payload May 29 17:44:26 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:26 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:26 volumio volumio[1006]: info: ------------------------------ 23ms May 29 17:44:26 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:26 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:26 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:26 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:26 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:26 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:26 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:26 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:26 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:26 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:26 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:26 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:26 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:26 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:26 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:27 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:27 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:27 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:27 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:27 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:27 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:27 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:27 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:27 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:28 volumio go-librespot[29295]: time="2025-05-29T17:44:28+09:00" level=trace msg="sent dealer ping" May 29 17:44:28 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:28 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:28 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:28 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:28 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:28 volumio volumio[1006]: SPOTIFY: SETTING SPOTIFY VOLUME 60 May 29 17:44:28 volumio volumio[1006]: info: Sending Spotify command with payload to local API: /player/volume May 29 17:44:28 volumio go-librespot[29295]: time="2025-05-29T17:44:28+09:00" level=debug msg="update volume to 39321/65535" May 29 17:44:28 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:28 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:28 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:28 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:28 volumio go-librespot[29295]: time="2025-05-29T17:44:28+09:00" level=trace msg="received dealer pong" May 29 17:44:28 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:28 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:28 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:28 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:28 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:28 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:28 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:28 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:29 volumio go-librespot[29295]: time="2025-05-29T17:44:29+09:00" level=debug msg="put connect state because VOLUME_CHANGED" May 29 17:44:29 volumio go-librespot[29295]: time="2025-05-29T17:44:29+09:00" level=trace msg="emitting websocket event: volume" May 29 17:44:29 volumio volumio[1006]: SPOTIFY: received: {"type":"volume","data":{"value":60,"max":100}} May 29 17:44:29 volumio volumio[1006]: SPOTIFY: RECEIVED SPOTIFY VOLUME 60 May 29 17:44:30 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:30 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:30 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:30 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:30 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:30 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:30 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:30 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:30 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:30 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:32 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:32 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:32 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:32 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:32 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:32 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:32 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:32 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:32 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:32 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:34 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:34 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:34 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:34 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:34 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:34 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:34 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:34 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:34 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:34 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:35 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:35 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:36 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:36 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:36 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:36 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:36 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:36 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:36 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:36 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:37 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:37 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:38 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:38 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:38 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:38 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:38 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:38 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:38 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:38 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:39 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:39 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:40 volumio volumio[1006]: info: May 29 17:44:40 volumio volumio[1006]: ---------------------------- Client requests Volume - May 29 17:44:40 volumio volumio[1006]: info: VolumeController::SetAlsaVolume- May 29 17:44:40 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:40 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:40 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:40 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:40 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:40 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:40 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:40 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:40 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:40 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 May 29 17:44:40 volumio volumio[1006]: SPOTIFY: SPOTIFY VOLUME 60 May 29 17:44:40 volumio volumio[1006]: SPOTIFY: VOLUMIO VOLUME 55 May 29 17:44:40 volumio volumio[1006]: SPOTIFY: DELTA VOLUME ENOUGH: true May 29 17:44:40 volumio volumio[1006]: info: Setting Spotify Volume from Volumio: 55 May 29 17:44:40 volumio volumio[1006]: info: May 29 17:44:40 volumio volumio[1006]: ---------------------------- MPD announces state update: mixer May 29 17:44:40 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:40 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:40 volumio volumio[1006]: info: sendMpdCommand status took 2 milliseconds May 29 17:44:40 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:40 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:40 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 2 milliseconds May 29 17:44:40 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:40 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:40 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:40 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:40 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":23360,"duration":169,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"252 Kbps","isStreaming":false,"title":"恋は桃色","artist":"Pearl & The Oysters","album":"HOSONO HOUSE COVERS","uri":"NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a","trackType":"m4a"} May 29 17:44:40 volumio volumio[1006]: verbose: CURRENT POSITION 2 May 29 17:44:40 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:44:40 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus play May 29 17:44:40 volumio volumio[1006]: info: Received an update from plugin. extracting info from payload May 29 17:44:40 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:40 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:40 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:40 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:40 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:40 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:40 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:40 volumio volumio[1006]: info: ------------------------------ 25ms May 29 17:44:40 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:40 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:40 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:40 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:40 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:40 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:40 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:40 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:40 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:40 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:40 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 May 29 17:44:40 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 May 29 17:44:40 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:40 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:40 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:40 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:40 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:40 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:41 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:41 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:41 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: May 29 17:44:41 volumio volumio[1006]: ---------------------------- Client requests Volume - May 29 17:44:41 volumio volumio[1006]: info: VolumeController::SetAlsaVolume- May 29 17:44:41 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:41 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:41 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:41 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:41 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:41 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:41 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 29 17:44:41 volumio volumio[1006]: SPOTIFY: SPOTIFY VOLUME 55 May 29 17:44:41 volumio volumio[1006]: SPOTIFY: VOLUMIO VOLUME 50 May 29 17:44:41 volumio volumio[1006]: SPOTIFY: DELTA VOLUME ENOUGH: true May 29 17:44:41 volumio volumio[1006]: info: Setting Spotify Volume from Volumio: 50 May 29 17:44:41 volumio volumio[1006]: info: May 29 17:44:41 volumio volumio[1006]: ---------------------------- MPD announces state update: mixer May 29 17:44:41 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:41 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:41 volumio volumio[1006]: info: sendMpdCommand status took 2 milliseconds May 29 17:44:41 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:41 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:41 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 3 milliseconds May 29 17:44:41 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:41 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":24228,"duration":169,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"252 Kbps","isStreaming":false,"title":"恋は桃色","artist":"Pearl & The Oysters","album":"HOSONO HOUSE COVERS","uri":"NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a","trackType":"m4a"} May 29 17:44:41 volumio volumio[1006]: verbose: CURRENT POSITION 2 May 29 17:44:41 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:44:41 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus play May 29 17:44:41 volumio volumio[1006]: info: Received an update from plugin. extracting info from payload May 29 17:44:41 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:41 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:41 volumio volumio[1006]: info: ------------------------------ 24ms May 29 17:44:41 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:41 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:41 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:41 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:41 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:41 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:41 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:41 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:41 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:44:41 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:44:41 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 29 17:44:41 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:41 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:41 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:42 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:42 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:42 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:42 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:42 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:42 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:42 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:42 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:42 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:42 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:42 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:42 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:42 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:42 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:42 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:42 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:42 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:42 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:42 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:42 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:43 volumio volumio[1006]: SPOTIFY: SETTING SPOTIFY VOLUME 50 May 29 17:44:43 volumio volumio[1006]: info: Sending Spotify command with payload to local API: /player/volume May 29 17:44:43 volumio go-librespot[29295]: time="2025-05-29T17:44:43+09:00" level=debug msg="update volume to 32767/65535" May 29 17:44:43 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:43 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:44 volumio go-librespot[29295]: time="2025-05-29T17:44:44+09:00" level=debug msg="put connect state because VOLUME_CHANGED" May 29 17:44:44 volumio go-librespot[29295]: time="2025-05-29T17:44:44+09:00" level=trace msg="emitting websocket event: volume" May 29 17:44:44 volumio volumio[1006]: SPOTIFY: received: {"type":"volume","data":{"value":50,"max":100}} May 29 17:44:44 volumio volumio[1006]: SPOTIFY: RECEIVED SPOTIFY VOLUME 50 May 29 17:44:44 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:44 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:44 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:44 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:44 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:44 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:44 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:44 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:45 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:45 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:46 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:46 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:46 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:46 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:46 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:46 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:46 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:46 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:47 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:47 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:48 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:48 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:48 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:48 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:48 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:48 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:48 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:48 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:49 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:49 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:50 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:50 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:50 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:50 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:50 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:50 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:50 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:50 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:51 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:51 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:52 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:52 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:52 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:52 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:52 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:52 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:52 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:52 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:53 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:53 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:54 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:54 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:54 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:54 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:54 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:54 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:54 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:54 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:56 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:56 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:56 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:56 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:56 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:56 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:56 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:56 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:56 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:56 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:58 volumio go-librespot[29295]: time="2025-05-29T17:44:58+09:00" level=trace msg="sent dealer ping" May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:58 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:58 volumio go-librespot[29295]: time="2025-05-29T17:44:58+09:00" level=trace msg="received dealer pong" May 29 17:44:58 volumio volumio[1006]: info: CALLMETHOD: audio_interface alsa_controller saveAlsaOptions [object Object] May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveAlsaOptions May 29 17:44:58 volumio volumio[1006]: info: Preparing to save Alsa Options, stopping services first May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:58 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::volumioPause May 29 17:44:58 volumio volumio[1006]: info: CoreStateMachine::pause May 29 17:44:58 volumio volumio[1006]: info: CoreStateMachine::stPlaybackTimer May 29 17:44:58 volumio volumio[1006]: info: CoreStateMachine::servicePause May 29 17:44:58 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::servicePause May 29 17:44:58 volumio volumio[1006]: info: ControllerMpd::pause May 29 17:44:58 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand pause May 29 17:44:58 volumio volumio[1006]: info: Saving Audio Output to: {"output_device":{"value":"1","label":"Headphones"},"i2s":false,"i2sid":{"value":"adafruit-max98357","label":"Adafruit MAX98357"}} May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 29 17:44:58 volumio volumio[1006]: info: Found match in Cards Database: setting mixer PCM for card Headphones May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::volumioUpdateVolumeSettings May 29 17:44:58 volumio volumio[1006]: info: Updating Volume Controller Parameters: Device: 1 Name: Headphones Mixer: PCM Max Vol: 100 Vol Curve; logarithmic Vol Steps: 5 May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume May 29 17:44:58 volumio volumio[1006]: info: Disabling external Volume Control May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::getUIConfigOnPlugin May 29 17:44:58 volumio volumio[1006]: info: Preparing to generate the ALSA configuration file May 29 17:44:58 volumio volumio[1006]: info: May 29 17:44:58 volumio volumio[1006]: ---------------------------- MPD announces state update: player May 29 17:44:58 volumio volumio[1006]: info: sendMpdCommand pause took 285 milliseconds May 29 17:44:58 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:44:58 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:44:58 volumio volumio[1006]: info: sendMpdCommand status took 39 milliseconds May 29 17:44:58 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:44:58 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:44:58 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 1 milliseconds May 29 17:44:58 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:44:58 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:44:58 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:58 volumio volumio[1006]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":40982,"duration":169,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"252 Kbps","isStreaming":false,"title":"恋は桃色","artist":"Pearl & The Oysters","album":"HOSONO HOUSE COVERS","uri":"NAS/MyMusic/My Music/細野晴臣/Compilations/HOSONO HOUSE COVERS/01 恋は桃色.m4a","trackType":"m4a"} May 29 17:44:58 volumio volumio[1006]: verbose: CURRENT POSITION 2 May 29 17:44:58 volumio volumio[1006]: info: CoreStateMachine::syncState stateService pause May 29 17:44:58 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus pause May 29 17:44:58 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:58 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:58 volumio volumio[1006]: info: CoreStateMachine::stPlaybackTimer May 29 17:44:58 volumio volumio[1006]: info: ------------------------------ 54ms May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus May 29 17:44:58 volumio volumio[1006]: info: Asound.conf file unchanged, so no further update is needed May 29 17:44:58 volumio volumio[1006]: info: Output device has changed, restarting MPD May 29 17:44:58 volumio sudo[20391]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf May 29 17:44:58 volumio sudo[20391]: pam_unix(sudo:session): session opened for user root by (uid=0) May 29 17:44:58 volumio sudo[20391]: pam_unix(sudo:session): session closed for user root May 29 17:44:58 volumio volumio[1006]: info: Output device has changed, restarting Shairport Sync May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 29 17:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 29 17:44:58 volumio sudo[20394]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service May 29 17:44:58 volumio sudo[20394]: pam_unix(sudo:session): session opened for user root by (uid=0) May 29 17:44:59 volumio systemd[1]: Stopping Music Player Daemon... May 29 17:44:59 volumio volumio[1006]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 May 29 17:44:59 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:59 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: pause | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:59 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508258588 May 29 17:44:59 volumio volumio[1006]: info: [LastFM] Song has been paused, so also pausing timer. May 29 17:44:59 volumio volumio[1006]: -------------------------------------------------// P A U S I N G (remaining: 52484 milliseconds) May 29 17:44:59 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 29 17:44:59 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:59 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:59 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:59 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:59 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:59 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:59 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:59 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:59 volumio volumio[1006]: info: MPD Permissions set May 29 17:44:59 volumio volumio[1006]: info: VolumeController:: Volume=50 Mute =false May 29 17:44:59 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:44:59 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:59 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:44:59 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:44:59 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: pause | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:44:59 volumio volumio[1006]: info: =================> [timer] is active: false | can continue: true | timer started at: 1748508258588 May 29 17:44:59 volumio volumio[1006]: info: [LastFM] Song has been paused, so also pausing timer. May 29 17:44:59 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 29 17:44:59 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 29 17:44:59 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam May 29 17:44:59 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam May 29 17:44:59 volumio volumio[1006]: info: Starting Shairport Sync May 29 17:44:59 volumio sudo[20404]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync May 29 17:44:59 volumio sudo[20404]: pam_unix(sudo:session): session opened for user root by (uid=0) May 29 17:44:59 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:59 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:59 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:59 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... May 29 17:44:59 volumio systemd[1]: shairport-sync.service: Succeeded. May 29 17:44:59 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. May 29 17:44:59 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:44:59 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:44:59 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:44:59 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. May 29 17:44:59 volumio systemd[1]: mpd.service: Succeeded. May 29 17:44:59 volumio systemd[1]: Stopped Music Player Daemon. May 29 17:44:59 volumio sudo[20404]: pam_unix(sudo:session): session closed for user root May 29 17:44:59 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:59 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:59 volumio volumio[1006]: info: Shairport-Sync Started May 29 17:44:59 volumio systemd[1]: Starting Music Player Daemon... May 29 17:44:59 volumio sudo[20407]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log May 29 17:44:59 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:44:59 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:44:59 volumio sudo[20407]: pam_unix(sudo:session): session opened for user root by (uid=0) May 29 17:44:59 volumio sudo[20407]: pam_unix(sudo:session): session closed for user root May 29 17:45:00 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:00 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:00 volumio mpd[20415]: May 29 17:45 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg May 29 17:45:00 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:00 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:00 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:00 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:00 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:00 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:00 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:00 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:02 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:02 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:02 volumio volumio[1006]: info: CoreCommandRouter::volumioRetrieveVolumeLevels May 29 17:45:02 volumio volumio[1006]: info: CoreStateMachine::getcurrentVolume May 29 17:45:02 volumio volumio[1006]: info: CoreCommandRouter::volumioRetrievevolume May 29 17:45:02 volumio volumio[1006]: info: VolumeController:: Volume=50 Mute =false May 29 17:45:02 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:45:02 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:02 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:45:02 volumio volumio[1006]: info: CoreStateMachine::updateTrackBlock May 29 17:45:02 volumio volumio[1006]: info: CorePlayQueue::getTrackBlock May 29 17:45:02 volumio volumio[1006]: info: CoreCommandRouter::volumioRetrievevolume May 29 17:45:02 volumio systemd[1]: Started Music Player Daemon. May 29 17:45:02 volumio sudo[20394]: pam_unix(sudo:session): session closed for user root May 29 17:45:02 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:45:02 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: pause | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:45:02 volumio volumio[1006]: info: =================> [timer] is active: false | can continue: true | timer started at: 1748508258588 May 29 17:45:02 volumio volumio[1006]: info: [LastFM] Song has been paused, so also pausing timer. May 29 17:45:02 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 29 17:45:02 volumio volumio[1006]: error: updateQueue error: null May 29 17:45:02 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:45:02 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:45:02 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:45:02 volumio volumio[1006]: info: VolumeController:: Volume=50 Mute =false May 29 17:45:02 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:45:02 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:02 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:45:02 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:45:02 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: pause | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:45:02 volumio volumio[1006]: info: =================> [timer] is active: false | can continue: true | timer started at: 1748508258588 May 29 17:45:02 volumio volumio[1006]: info: [LastFM] Song has been paused, so also pausing timer. May 29 17:45:02 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 29 17:45:02 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:02 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:02 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:02 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:02 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:02 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:02 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:02 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:02 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:45:03 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:45:03 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:45:03 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:03 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:03 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:03 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:04 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:04 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:04 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:04 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:04 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:04 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:04 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:04 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:04 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:04 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:06 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:06 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:06 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:06 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:06 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:06 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:06 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:06 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:06 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:06 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::volumioNext May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::next May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::stop May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::setConsumeUpdateService undefined May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::updateTrackBlock May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrackBlock May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::stPlaybackTimer May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::serviceStop May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrack 2 May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::serviceStop May 29 17:45:07 volumio volumio[1006]: info: ControllerMpd::stop May 29 17:45:07 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand stop May 29 17:45:07 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:45:07 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 169 | title: 恋は桃色 | previous title: 恋は桃色 May 29 17:45:07 volumio volumio[1006]: info: =================> [timer] is active: false | can continue: true | timer started at: 1748508258588 May 29 17:45:07 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 29 17:45:07 volumio volumio[1006]: info: sendMpdCommand stop took 9 milliseconds May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::play index undefined May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::setConsumeUpdateService undefined May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrack 3 May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::startPlaybackTimer May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrack 3 May 29 17:45:07 volumio volumio[1006]: verbose: ControllerMpd::clearAddPlayTracks NAS/MyMusic/My Music/細野晴臣/Hochono House/01 相合傘 ~ Broken Radio Version.m4a May 29 17:45:07 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand stop May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::updateTrackBlock May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrackBlock May 29 17:45:07 volumio volumio[1006]: info: sendMpdCommand stop took 2 milliseconds May 29 17:45:07 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand clear May 29 17:45:07 volumio volumio[1006]: info: sendMpdCommand clear took 1 milliseconds May 29 17:45:07 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand add "NAS/MyMusic/My Music/細野晴臣/Hochono House/01 相合傘 ~ Broken Radio Version.m4a" May 29 17:45:07 volumio volumio[1006]: info: May 29 17:45:07 volumio volumio[1006]: ---------------------------- MPD announces system playlist update May 29 17:45:07 volumio volumio[1006]: info: Ignoring MPD Status Update May 29 17:45:07 volumio volumio[1006]: info: May 29 17:45:07 volumio volumio[1006]: ---------------------------- MPD announces system playlist update May 29 17:45:07 volumio volumio[1006]: info: Ignoring MPD Status Update May 29 17:45:07 volumio volumio[1006]: info: sendMpdCommand add "NAS/MyMusic/My Music/細野晴臣/Hochono House/01 相合傘 ~ Broken Radio Version.m4a" took 4 milliseconds May 29 17:45:07 volumio volumio[1006]: info: ------------------------------ 4ms May 29 17:45:07 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand play May 29 17:45:07 volumio volumio[1006]: info: ------------------------------ 4ms May 29 17:45:07 volumio volumio[1006]: info: sendMpdCommand play took 5 milliseconds May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrack 3 May 29 17:45:07 volumio volumio[1006]: info: May 29 17:45:07 volumio volumio[1006]: ---------------------------- MPD announces state update: player May 29 17:45:07 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:45:07 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:45:07 volumio volumio[1006]: info: May 29 17:45:07 volumio volumio[1006]: ---------------------------- MPD announces state update: player May 29 17:45:07 volumio volumio[1006]: info: sendMpdCommand status took 12 milliseconds May 29 17:45:07 volumio volumio[1006]: info: ControllerMpd::getState May 29 17:45:07 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand status May 29 17:45:07 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:45:07 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:45:07 volumio volumio[1006]: info: sendMpdCommand status took 6 milliseconds May 29 17:45:07 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 7 milliseconds May 29 17:45:07 volumio volumio[1006]: verbose: ControllerMpd::parseState May 29 17:45:07 volumio volumio[1006]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 29 17:45:07 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:45:07 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrack 3 May 29 17:45:07 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":79,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"250 Kbps","isStreaming":false,"title":"相合傘 ~ Broken Radio Version","artist":"細野晴臣","album":"Hochono House","uri":"NAS/MyMusic/My Music/細野晴臣/Hochono House/01 相合傘 ~ Broken Radio Version.m4a","trackType":"m4a"} May 29 17:45:07 volumio volumio[1006]: verbose: CURRENT POSITION 3 May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus stop May 29 17:45:07 volumio volumio[1006]: info: ------------------------------ 25ms May 29 17:45:07 volumio volumio[1006]: info: sendMpdCommand playlistinfo took 3 milliseconds May 29 17:45:07 volumio volumio[1006]: verbose: ControllerMpd::parseTrackInfo May 29 17:45:07 volumio volumio[1006]: info: ControllerMpd::pushState May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::servicePushState May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrack 3 May 29 17:45:07 volumio volumio[1006]: verbose: STATE SERVICE {"status":"play","position":0,"seek":983,"duration":79,"samplerate":44.1,"bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"250 Kbps","isStreaming":false,"title":"相合傘 ~ Broken Radio Version","artist":"細野晴臣","album":"Hochono House","uri":"NAS/MyMusic/My Music/細野晴臣/Hochono House/01 相合傘 ~ Broken Radio Version.m4a","trackType":"m4a"} May 29 17:45:07 volumio volumio[1006]: verbose: CURRENT POSITION 3 May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::syncState stateService play May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::syncState currentStatus play May 29 17:45:07 volumio volumio[1006]: info: Received an update from plugin. extracting info from payload May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrack 3 May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::pushState May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrack 3 May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState May 29 17:45:07 volumio volumio[1006]: info: ------------------------------ 36ms May 29 17:45:07 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:45:07 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 79 | title: 相合傘 ~ Broken Radio Version | previous title: 恋は桃色 May 29 17:45:07 volumio volumio[1006]: info: =================> [timer] is active: false | can continue: true | timer started at: 1748508258588 May 29 17:45:07 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:45:07 volumio volumio[1006]: info: [LastFM] Current track has sufficient metadata: title (相合傘 ~ Broken Radio Version) and artist (細野晴臣) passed on explicitly May 29 17:45:07 volumio volumio[1006]: info: [LastFM] Updating now playing May 29 17:45:07 volumio volumio[1006]: info: [LastFM] starting new timer for 43450 milliseconds [細野晴臣 - 相合傘 ~ Broken Radio Version]. May 29 17:45:07 volumio volumio[1006]: -------------------------------------------------// S T O P P I N G May 29 17:45:07 volumio volumio[1006]: -------------------------------------------------// S T A R T I N G May 29 17:45:07 volumio volumio[1006]: info: [LastFM] Timer started with time stamp 1748508307 May 29 17:45:07 volumio volumio[1006]: info: [LastFM] using existing timer May 29 17:45:07 volumio volumio[1006]: info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: play | service: mpd | duration: 79 | title: 相合傘 ~ Broken Radio Version | previous title: 相合傘 ~ Broken Radio Version May 29 17:45:07 volumio volumio[1006]: info: =================> [timer] is active: true | can continue: false | timer started at: 1748508307666 May 29 17:45:07 volumio volumio[1006]: info: [LastFM] Playback detected, evaluating parameters for scrobbling... May 29 17:45:07 volumio volumio[1006]: info: [LastFM] Same state as the one previously pushed. No need to do anything... May 29 17:45:07 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 29 17:45:07 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrack 3 May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrack 3 May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrack 3 May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrack 3 May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrack 3 May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrack 3 May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue May 29 17:45:07 volumio volumio[1006]: info: CoreStateMachine::getQueue May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getQueue May 29 17:45:07 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:07 volumio volumio[1006]: info: CorePlayQueue::getTrack 3 May 29 17:45:08 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:08 volumio volumio[1006]: info: CorePlayQueue::getTrack 3 May 29 17:45:08 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState May 29 17:45:08 volumio volumio[1006]: info: CorePlayQueue::getTrack 3 May 29 17:45:08 volumio volumio[1006]: info: [LastFM] updated "now playing" | artist: 細野晴臣 | title: 相合傘 ~ Broken Radio Version May 29 17:45:08 volumio volumio[1006]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 29 17:45:08 volumio volumio[1006]: TypeError: Cannot read property '@' of undefined May 29 17:45:08 volumio volumio[1006]: at Object.callback (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:342:14) May 29 17:45:08 volumio volumio[1006]: at /data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:60:13 May 29 17:45:08 volumio volumio[1006]: at Parser. (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:308:18) May 29 17:45:08 volumio volumio[1006]: at Parser.emit (events.js:315:20) May 29 17:45:08 volumio volumio[1006]: at SAXParser.onerror (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:123:26) May 29 17:45:08 volumio volumio[1006]: at emit (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:624:35) May 29 17:45:08 volumio volumio[1006]: at error (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:653:5) May 29 17:45:08 volumio volumio[1006]: at strictFail (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:677:7) May 29 17:45:08 volumio volumio[1006]: at closeTag (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:871:9) May 29 17:45:08 volumio volumio[1006]: at SAXParser.write (/data/plugins/user_interface/lastfm/node_modules/sax/lib/sax.js:1436:13) May 29 17:45:08 volumio volumio[1006]: at Parser.exports.Parser.Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:323:31) May 29 17:45:08 volumio volumio[1006]: at Parser.parseString (/data/plugins/user_interface/lastfm/node_modules/xml2js/lib/parser.js:5:59) May 29 17:45:08 volumio volumio[1006]: at IncomingMessage. (/data/plugins/user_interface/lastfm/node_modules/simple-lastfm/lib/index.js:58:14) May 29 17:45:08 volumio volumio[1006]: at IncomingMessage.emit (events.js:327:22) May 29 17:45:08 volumio volumio[1006]: at endReadableNT (internal/streams/readable.js:1327:12) May 29 17:45:08 volumio volumio[1006]: at processTicksAndRejections (internal/process/task_queues.js:80:21) May 29 17:45:08 volumio volumio[1006]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 29 17:45:09 volumio sudo[20490]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-29 17:44 May 29 17:45:09 volumio sudo[20490]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="a01a833dd28483f88cb390596f5090b7187992af" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 27 Feb 2025 11:42:54 AM CET" VOLUMIO_VERSION="3.795" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="4049a67f1c09d4a94e033ba35a80a144"